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/03/22 17:13:47 UTC
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk-9) - Build # 4517 -
Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4517/
Java: 64bit/jdk-9 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestStopPoll
Error Message:
expected:<499> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<499> but was:<0>
at __randomizedtesting.SeedInfo.seed([D43BA5FEC8063E6F:C718DBF21EEFF95A]: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.handler.TestReplicationHandler.doTestStopPoll(TestReplicationHandler.java:593)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 1856 lines...]
[junit4] JVM J1: stdout was not empty, see: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/build/core/test/temp/junit4-J1-20180322_153550_22111370709214301021190.sysout
[junit4] >>> JVM J1 emitted unexpected output (verbatim) ----
[junit4] codec: SimpleText, pf: Memory, dvf: Lucene70
[junit4] <<< JVM J1: EOF ----
[...truncated 10268 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 0 INFO (SUITE-TestReplicationHandler-seed#[D43BA5FEC8063E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/init-core-data-001
[junit4] 2> 115 INFO (SUITE-TestReplicationHandler-seed#[D43BA5FEC8063E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 188 INFO (SUITE-TestReplicationHandler-seed#[D43BA5FEC8063E6F]-worker) [ ] o.e.j.u.log Logging initialized @2092ms to org.eclipse.jetty.util.log.Slf4jLog
[junit4] 2> 208 INFO (SUITE-TestReplicationHandler-seed#[D43BA5FEC8063E6F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="None") w/ MAC_OS_X supressed clientAuth
[junit4] IGNOR/A 0.01s J0 | TestReplicationHandler.doTestIndexFetchOnMasterRestart
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl="https://issues.apache.org/jira/browse/SOLR-9036"))
[junit4] 2> 228 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestStopPoll
[junit4] 2> 229 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/collection1
[junit4] 2> 560 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T21:27:37Z, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 575 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 575 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 578 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 594 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22f8d148{/solr,null,AVAILABLE}
[junit4] 2> 639 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4fc3a96a{HTTP/1.1,[http/1.1]}{127.0.0.1:53806}
[junit4] 2> 639 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.Server Started @2545ms
[junit4] 2> 640 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/collection1/data, hostPort=53806}
[junit4] 2> 666 ERROR (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 666 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 672 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 672 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 714 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-22T15:58:18.245411Z
[junit4] 2> 803 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 809 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/solr.xml
[junit4] 2> 1070 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 1070 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 1555 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/.
[junit4] 2> 1556 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1560 INFO (coreLoadExecutor-6-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1612 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1671 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1688 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 1689 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/./collection1, trusted=true
[junit4] 2> 1737 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1744 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/./collection1/data/]
[junit4] 2> 1775 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.758114295606474]
[junit4] 2> 2147 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2147 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2150 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=58.62890625, floorSegmentMB=1.1484375, forceMergeDeletesPctAllowed=28.48155996977784, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2171 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@282f181f[collection1] main]
[junit4] 2> 2184 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-001/collection1/conf
[junit4] 2> 2215 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 2216 INFO (coreLoadExecutor-6-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2307 INFO (searcherExecutor-7-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@282f181f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2315 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/collection1
[junit4] 2> 2322 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T21:27:37Z, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2324 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2324 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2325 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 2326 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@172aa24b{/solr,null,AVAILABLE}
[junit4] 2> 2327 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@63bb2224{HTTP/1.1,[http/1.1]}{127.0.0.1:53809}
[junit4] 2> 2327 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.Server Started @4233ms
[junit4] 2> 2327 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/collection1/data, hostPort=53809}
[junit4] 2> 2327 ERROR (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2328 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2328 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 2328 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2328 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-03-22T15:58:19.901681Z
[junit4] 2> 2329 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/solr.xml
[junit4] 2> 2341 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 2341 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 2384 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/.
[junit4] 2> 2384 INFO (TEST-TestReplicationHandler.doTestStopPoll-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 2385 INFO (coreLoadExecutor-16-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 2397 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2416 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 2419 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 2419 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/./collection1, trusted=true
[junit4] 2> 2419 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2419 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/./collection1/data/]
[junit4] 2> 2421 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.758114295606474]
[junit4] 2> 2472 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2472 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2473 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=58.62890625, floorSegmentMB=1.1484375, forceMergeDeletesPctAllowed=28.48155996977784, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2474 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@53a34c31[collection1] main]
[junit4] 2> 2474 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001/solr-instance-002/collection1/conf
[junit4] 2> 2483 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 2483 INFO (coreLoadExecutor-16-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2484 INFO (searcherExecutor-17-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@53a34c31[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2686 INFO (qtp279121836-19) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=12
[junit4] 2> 2734 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 2734 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 2734 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 2734 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 2734 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
[junit4] 2> 2736 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2736 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1ff74f13 commitCommandVersion:0
[junit4] 2> 2738 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@36e2aac6[collection1] main]
[junit4] 2> 2739 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2740 INFO (searcherExecutor-17-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@36e2aac6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2747 INFO (qtp279121836-15) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=73
[junit4] 2> 2858 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0]} 0 97
[junit4] 2> 2861 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 1
[junit4] 2> 2865 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0
[junit4] 2> 2867 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 2868 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 2870 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5]} 0 0
[junit4] 2> 2873 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6]} 0 0
[junit4] 2> 2875 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7]} 0 0
[junit4] 2> 2879 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8]} 0 0
[junit4] 2> 2882 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9]} 0 0
[junit4] 2> 2886 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[10]} 0 0
[junit4] 2> 2889 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[11]} 0 1
[junit4] 2> 2895 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[12]} 0 3
[junit4] 2> 2903 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13]} 0 1
[junit4] 2> 2906 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[14]} 0 0
[junit4] 2> 2913 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[15]} 0 2
[junit4] 2> 2918 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16]} 0 1
[junit4] 2> 2925 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17]} 0 2
[junit4] 2> 2934 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[18]} 0 0
[junit4] 2> 2937 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19]} 0 0
[junit4] 2> 2947 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[20]} 0 5
[junit4] 2> 2949 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[21]} 0 0
[junit4] 2> 2951 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[22]} 0 0
[junit4] 2> 2953 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[23]} 0 0
[junit4] 2> 2972 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[24]} 0 3
[junit4] 2> 2976 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[25]} 0 1
[junit4] 2> 2979 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[26]} 0 0
[junit4] 2> 2980 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[27]} 0 0
[junit4] 2> 2982 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[28]} 0 0
[junit4] 2> 2983 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[29]} 0 0
[junit4] 2> 2985 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[30]} 0 0
[junit4] 2> 2987 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[31]} 0 1
[junit4] 2> 2989 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[32]} 0 0
[junit4] 2> 2995 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[33]} 0 0
[junit4] 2> 2997 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[34]} 0 0
[junit4] 2> 3001 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[35]} 0 1
[junit4] 2> 3003 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[36]} 0 0
[junit4] 2> 3004 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[37]} 0 0
[junit4] 2> 3006 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[38]} 0 0
[junit4] 2> 3009 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[39]} 0 0
[junit4] 2> 3013 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[40]} 0 1
[junit4] 2> 3014 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[41]} 0 0
[junit4] 2> 3016 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[42]} 0 0
[junit4] 2> 3018 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43]} 0 0
[junit4] 2> 3023 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[44]} 0 4
[junit4] 2> 3025 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[45]} 0 0
[junit4] 2> 3029 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[46]} 0 0
[junit4] 2> 3033 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[47]} 0 0
[junit4] 2> 3035 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[48]} 0 0
[junit4] 2> 3036 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[49]} 0 0
[junit4] 2> 3045 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[50]} 0 0
[junit4] 2> 3047 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[51]} 0 0
[junit4] 2> 3049 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[52]} 0 0
[junit4] 2> 3052 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[53]} 0 0
[junit4] 2> 3053 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[54]} 0 0
[junit4] 2> 3062 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[55]} 0 3
[junit4] 2> 3067 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[56]} 0 0
[junit4] 2> 3069 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[57]} 0 0
[junit4] 2> 3070 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[58]} 0 0
[junit4] 2> 3080 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[59]} 0 3
[junit4] 2> 3092 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[60]} 0 0
[junit4] 2> 3108 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[61]} 0 0
[junit4] 2> 3116 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[62]} 0 0
[junit4] 2> 3122 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[63]} 0 0
[junit4] 2> 3124 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[64]} 0 0
[junit4] 2> 3126 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[65]} 0 0
[junit4] 2> 3128 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[66]} 0 0
[junit4] 2> 3129 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[67]} 0 0
[junit4] 2> 3131 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[68]} 0 0
[junit4] 2> 3132 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[69]} 0 0
[junit4] 2> 3134 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[70]} 0 0
[junit4] 2> 3135 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[71]} 0 0
[junit4] 2> 3137 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[72]} 0 0
[junit4] 2> 3141 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[73]} 0 0
[junit4] 2> 3143 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[74]} 0 0
[junit4] 2> 3144 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[75]} 0 0
[junit4] 2> 3146 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[76]} 0 0
[junit4] 2> 3147 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[77]} 0 0
[junit4] 2> 3148 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[78]} 0 0
[junit4] 2> 3150 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[79]} 0 0
[junit4] 2> 3151 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[80]} 0 0
[junit4] 2> 3152 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[81]} 0 0
[junit4] 2> 3154 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[82]} 0 0
[junit4] 2> 3162 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[83]} 0 0
[junit4] 2> 3163 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[84]} 0 0
[junit4] 2> 3164 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[85]} 0 0
[junit4] 2> 3166 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[86]} 0 0
[junit4] 2> 3169 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[87]} 0 0
[junit4] 2> 3171 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[88]} 0 0
[junit4] 2> 3174 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[89]} 0 0
[junit4] 2> 3177 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[90]} 0 0
[junit4] 2> 3179 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[91]} 0 0
[junit4] 2> 3181 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[92]} 0 0
[junit4] 2> 3183 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[93]} 0 0
[junit4] 2> 3185 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[94]} 0 0
[junit4] 2> 3186 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[95]} 0 0
[junit4] 2> 3187 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[96]} 0 0
[junit4] 2> 3189 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[97]} 0 0
[junit4] 2> 3191 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[98]} 0 0
[junit4] 2> 3194 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[99]} 0 2
[junit4] 2> 3197 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[100]} 0 0
[junit4] 2> 3198 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[101]} 0 0
[junit4] 2> 3200 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[102]} 0 1
[junit4] 2> 3202 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[103]} 0 0
[junit4] 2> 3205 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[104]} 0 2
[junit4] 2> 3219 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[105]} 0 6
[junit4] 2> 3221 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[106]} 0 0
[junit4] 2> 3223 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[107]} 0 0
[junit4] 2> 3225 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[108]} 0 0
[junit4] 2> 3226 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[109]} 0 0
[junit4] 2> 3228 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[110]} 0 1
[junit4] 2> 3231 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[111]} 0 0
[junit4] 2> 3233 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[112]} 0 0
[junit4] 2> 3235 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[113]} 0 0
[junit4] 2> 3255 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[114]} 0 11
[junit4] 2> 3259 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[115]} 0 0
[junit4] 2> 3266 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[116]} 0 0
[junit4] 2> 3268 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[117]} 0 0
[junit4] 2> 3278 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[118]} 0 0
[junit4] 2> 3279 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[119]} 0 0
[junit4] 2> 3281 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[120]} 0 0
[junit4] 2> 3282 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[121]} 0 0
[junit4] 2> 3283 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[122]} 0 0
[junit4] 2> 3285 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[123]} 0 0
[junit4] 2> 3287 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[124]} 0 0
[junit4] 2> 3291 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[125]} 0 0
[junit4] 2> 3293 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[126]} 0 0
[junit4] 2> 3386 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[127]} 0 92
[junit4] 2> 3388 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[128]} 0 0
[junit4] 2> 3389 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[129]} 0 0
[junit4] 2> 3398 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[130]} 0 0
[junit4] 2> 3399 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[131]} 0 0
[junit4] 2> 3402 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[132]} 0 0
[junit4] 2> 3420 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[133]} 0 0
[junit4] 2> 3421 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[134]} 0 0
[junit4] 2> 3423 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[135]} 0 0
[junit4] 2> 3424 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[136]} 0 0
[junit4] 2> 3428 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[137]} 0 1
[junit4] 2> 3430 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[138]} 0 0
[junit4] 2> 3435 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[139]} 0 0
[junit4] 2> 3437 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[140]} 0 0
[junit4] 2> 3438 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[141]} 0 0
[junit4] 2> 3439 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[142]} 0 0
[junit4] 2> 3441 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[143]} 0 0
[junit4] 2> 3442 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[144]} 0 0
[junit4] 2> 3443 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[145]} 0 0
[junit4] 2> 3445 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[146]} 0 0
[junit4] 2> 3446 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[147]} 0 0
[junit4] 2> 3447 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[148]} 0 0
[junit4] 2> 3449 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[149]} 0 0
[junit4] 2> 3450 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[150]} 0 0
[junit4] 2> 3452 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[151]} 0 0
[junit4] 2> 3453 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[152]} 0 0
[junit4] 2> 3455 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[153]} 0 0
[junit4] 2> 3457 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[154]} 0 0
[junit4] 2> 3459 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[155]} 0 0
[junit4] 2> 3462 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[156]} 0 1
[junit4] 2> 3463 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[157]} 0 0
[junit4] 2> 3464 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[158]} 0 0
[junit4] 2> 3466 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[159]} 0 0
[junit4] 2> 3467 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[160]} 0 0
[junit4] 2> 3468 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[161]} 0 0
[junit4] 2> 3468 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[162]} 0 0
[junit4] 2> 3468 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[163]} 0 0
[junit4] 2> 3473 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[164]} 0 0
[junit4] 2> 3474 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[165]} 0 0
[junit4] 2> 3478 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[166]} 0 3
[junit4] 2> 3481 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[167]} 0 0
[junit4] 2> 3482 INFO (qtp279121836-17) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[168]} 0 0
[junit4] 2> 3484 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[169]} 0 0
[junit4] 2> 3484 INFO (qtp279121836-17) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1521734300310
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 3485 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[170]} 0 0
[junit4] 2> 3485 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1ff74f13 commitCommandVersion:0
[junit4] 2> 3486 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[171]} 0 0
[junit4] 2> 3487 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[172]} 0 0
[junit4] 2> 3489 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[173]} 0 0
[junit4] 2> 3490 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[174]} 0 0
[junit4] 2> 3491 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[175]} 0 0
[junit4] 2> 3493 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[176]} 0 0
[junit4] 2> 3495 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[177]} 0 0
[junit4] 2> 3497 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[178]} 0 0
[junit4] 2> 3498 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[179]} 0 0
[junit4] 2> 3500 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[180]} 0 0
[junit4] 2> 3506 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[181]} 0 0
[junit4] 2> 3507 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[182]} 0 0
[junit4] 2> 3508 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[183]} 0 0
[junit4] 2> 3510 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[184]} 0 0
[junit4] 2> 3511 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[185]} 0 0
[junit4] 2> 3512 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[186]} 0 0
[junit4] 2> 3513 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[187]} 0 0
[junit4] 2> 3514 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[188]} 0 0
[junit4] 2> 3515 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[189]} 0 0
[junit4] 2> 3515 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[190]} 0 0
[junit4] 2> 3515 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[191]} 0 0
[junit4] 2> 3521 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[192]} 0 0
[junit4] 2> 3522 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[193]} 0 0
[junit4] 2> 3523 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[194]} 0 0
[junit4] 2> 3525 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[195]} 0 0
[junit4] 2> 3525 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@76d0d91b[collection1] main]
[junit4] 2> 3525 INFO (indexFetcher-21-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 3526 INFO (searcherExecutor-17-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@76d0d91b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 3526 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[196]} 0 0
[junit4] 2> 3527 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[197]} 0 0
[junit4] 2> 3528 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[198]} 0 0
[junit4] 2> 3530 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[199]} 0 0
[junit4] 2> 3531 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[200]} 0 0
[junit4] 2> 3532 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[201]} 0 0
[junit4] 2> 3533 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[202]} 0 0
[junit4] 2> 3535 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[203]} 0 0
[junit4] 2> 3536 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[204]} 0 0
[junit4] 2> 3537 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[205]} 0 0
[junit4] 2> 3538 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[206]} 0 0
[junit4] 2> 3540 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[207]} 0 0
[junit4] 2> 3541 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[208]} 0 0
[junit4] 2> 3542 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[209]} 0 0
[junit4] 2> 3544 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[210]} 0 0
[junit4] 2> 3545 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[211]} 0 0
[junit4] 2> 3546 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[212]} 0 0
[junit4] 2> 3548 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[213]} 0 0
[junit4] 2> 3549 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[214]} 0 0
[junit4] 2> 3550 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[215]} 0 0
[junit4] 2> 3551 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[216]} 0 0
[junit4] 2> 3552 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[217]} 0 0
[junit4] 2> 3554 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[218]} 0 0
[junit4] 2> 3555 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[219]} 0 0
[junit4] 2> 3556 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[220]} 0 0
[junit4] 2> 3557 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[221]} 0 0
[junit4] 2> 3559 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[222]} 0 0
[junit4] 2> 3561 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[223]} 0 0
[junit4] 2> 3563 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[224]} 0 0
[junit4] 2> 3564 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[225]} 0 0
[junit4] 2> 3565 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[226]} 0 0
[junit4] 2> 3567 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[227]} 0 0
[junit4] 2> 3568 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[228]} 0 0
[junit4] 2> 3569 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[229]} 0 0
[junit4] 2> 3571 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[230]} 0 0
[junit4] 2> 3572 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[231]} 0 0
[junit4] 2> 3573 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[232]} 0 0
[junit4] 2> 3574 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[233]} 0 0
[junit4] 2> 3578 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[234]} 0 0
[junit4] 2> 3580 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[235]} 0 0
[junit4] 2> 3581 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[236]} 0 0
[junit4] 2> 3582 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[237]} 0 0
[junit4] 2> 3583 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[238]} 0 0
[junit4] 2> 3585 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[239]} 0 0
[junit4] 2> 3586 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[240]} 0 0
[junit4] 2> 3587 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[241]} 0 0
[junit4] 2> 3588 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[242]} 0 0
[junit4] 2> 3589 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[243]} 0 0
[junit4] 2> 3591 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[244]} 0 0
[junit4] 2> 3592 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[245]} 0 0
[junit4] 2> 3593 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[246]} 0 0
[junit4] 2> 3594 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[247]} 0 0
[junit4] 2> 3595 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[248]} 0 0
[junit4] 2> 3597 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[249]} 0 0
[junit4] 2> 3598 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[250]} 0 0
[junit4] 2> 3599 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[251]} 0 0
[junit4] 2> 3601 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[252]} 0 0
[junit4] 2> 3602 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[253]} 0 0
[junit4] 2> 3604 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[254]} 0 0
[junit4] 2> 3670 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[255]} 0 64
[junit4] 2> 3672 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[256]} 0 0
[junit4] 2> 3673 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[257]} 0 0
[junit4] 2> 3675 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[258]} 0 0
[junit4] 2> 3676 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[259]} 0 0
[junit4] 2> 3677 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[260]} 0 0
[junit4] 2> 3678 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[261]} 0 0
[junit4] 2> 3680 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[262]} 0 0
[junit4] 2> 3681 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[263]} 0 0
[junit4] 2> 3682 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[264]} 0 0
[junit4] 2> 3684 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[265]} 0 0
[junit4] 2> 3685 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[266]} 0 0
[junit4] 2> 3686 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[267]} 0 0
[junit4] 2> 3687 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[268]} 0 0
[junit4] 2> 3689 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[269]} 0 0
[junit4] 2> 3690 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[270]} 0 0
[junit4] 2> 3691 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[271]} 0 0
[junit4] 2> 3693 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[272]} 0 0
[junit4] 2> 3694 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[273]} 0 0
[junit4] 2> 3695 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[274]} 0 0
[junit4] 2> 3697 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[275]} 0 0
[junit4] 2> 3698 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[276]} 0 0
[junit4] 2> 3700 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[277]} 0 0
[junit4] 2> 3701 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[278]} 0 0
[junit4] 2> 3702 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[279]} 0 0
[junit4] 2> 3703 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[280]} 0 0
[junit4] 2> 3705 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[281]} 0 0
[junit4] 2> 3706 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[282]} 0 0
[junit4] 2> 3707 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[283]} 0 0
[junit4] 2> 3708 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[284]} 0 0
[junit4] 2> 3710 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[285]} 0 0
[junit4] 2> 3712 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[286]} 0 0
[junit4] 2> 3713 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[287]} 0 0
[junit4] 2> 3714 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[288]} 0 0
[junit4] 2> 3715 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[289]} 0 0
[junit4] 2> 3717 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[290]} 0 0
[junit4] 2> 3719 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[291]} 0 0
[junit4] 2> 3721 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[292]} 0 0
[junit4] 2> 3722 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[293]} 0 0
[junit4] 2> 3723 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[294]} 0 0
[junit4] 2> 3724 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[295]} 0 0
[junit4] 2> 3734 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[296]} 0 0
[junit4] 2> 3735 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[297]} 0 0
[junit4] 2> 3739 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[298]} 0 0
[junit4] 2> 3741 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[299]} 0 0
[junit4] 2> 3742 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[300]} 0 0
[junit4] 2> 3744 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[301]} 0 0
[junit4] 2> 3745 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[302]} 0 0
[junit4] 2> 3746 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[303]} 0 0
[junit4] 2> 3747 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[304]} 0 0
[junit4] 2> 3748 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[305]} 0 0
[junit4] 2> 3750 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[306]} 0 0
[junit4] 2> 3751 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[307]} 0 0
[junit4] 2> 3752 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[308]} 0 0
[junit4] 2> 3754 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[309]} 0 0
[junit4] 2> 3755 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[310]} 0 0
[junit4] 2> 3756 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[311]} 0 0
[junit4] 2> 3758 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[312]} 0 0
[junit4] 2> 3759 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[313]} 0 0
[junit4] 2> 3760 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[314]} 0 0
[junit4] 2> 3761 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[315]} 0 0
[junit4] 2> 3763 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[316]} 0 0
[junit4] 2> 3764 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[317]} 0 0
[junit4] 2> 3765 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[318]} 0 0
[junit4] 2> 3766 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[319]} 0 0
[junit4] 2> 3773 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[320]} 0 0
[junit4] 2> 3775 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[321]} 0 0
[junit4] 2> 3776 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[322]} 0 0
[junit4] 2> 3777 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[323]} 0 0
[junit4] 2> 3779 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[324]} 0 0
[junit4] 2> 3780 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[325]} 0 0
[junit4] 2> 3782 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[326]} 0 0
[junit4] 2> 3786 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[327]} 0 0
[junit4] 2> 3789 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[328]} 0 0
[junit4] 2> 3791 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[329]} 0 0
[junit4] 2> 3795 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[330]} 0 0
[junit4] 2> 3796 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[331]} 0 0
[junit4] 2> 3800 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[332]} 0 0
[junit4] 2> 3802 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[333]} 0 0
[junit4] 2> 3804 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[334]} 0 0
[junit4] 2> 3808 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[335]} 0 0
[junit4] 2> 3817 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[336]} 0 0
[junit4] 2> 3820 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[337]} 0 0
[junit4] 2> 3822 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[338]} 0 0
[junit4] 2> 3823 INFO (qtp279121836-21) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[339]} 0 0
[junit4] 2> 3826 INFO (qtp279121836-19) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[340]} 0 0
[junit4] 2> 3834 INFO (qtp279121836-21) [ x:c
[...truncated too long message...]
4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1637)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:188)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:168)
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473)
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:166)
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155)
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:527)
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:530)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:347)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:256)
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:279)
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:124)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:247)
[junit4] 2> at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:140)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 105497 INFO (qtp296858706-1054) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=4
[junit4] 2> 105499 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6d2c0cc8{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 105499 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=520379966
[junit4] 2> 105499 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 105499 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 105499 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 105500 INFO (coreCloseExecutor-629-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5ae8262a
[junit4] 2> 105500 INFO (coreCloseExecutor-629-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1525163562
[junit4] 2> 105503 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2dee2930{/solr,null,UNAVAILABLE}
[junit4] 2> 105503 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 105504 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestDetails
[junit4] 2> 105505 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2f4401e5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 105505 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=432596280
[junit4] 2> 105505 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 105505 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 105505 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 105506 INFO (coreCloseExecutor-631-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@564586fd
[junit4] 2> 105506 INFO (coreCloseExecutor-631-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1447397117
[junit4] 2> 105507 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@128ec26c{/solr,null,UNAVAILABLE}
[junit4] 2> 105507 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 105509 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@137932e8{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 105509 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1423358609
[junit4] 2> 105510 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 105510 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 105510 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 105510 INFO (coreCloseExecutor-633-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5ad32c7c
[junit4] 2> 105510 INFO (coreCloseExecutor-633-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1523788924
[junit4] 2> 105514 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b0021a5{/solr,null,UNAVAILABLE}
[junit4] 2> 105514 INFO (TEST-TestReplicationHandler.doTestDetails-seed#[D43BA5FEC8063E6F]) [ ] o.e.j.s.session Stopped scavenging
[junit4] IGNOR/A 0.00s J0 | TestReplicationHandler.doTestIndexAndConfigReplication
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl="https://issues.apache.org/jira/browse/SOLR-11673"))
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_D43BA5FEC8063E6F-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {name=BlockTreeOrds(blocksize=128), id=BlockTreeOrds(blocksize=128), newname=BlockTreeOrds(blocksize=128)}, docValues:{}, maxPointsInLeafNode=1368, maxMBSortInHeap=5.882707349361654, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7dbaf1a3), locale=uz, timezone=Etc/UCT
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=90628976,total=171966464
[junit4] 2> NOTE: All tests run in this JVM: [TestReplicationHandler]
[junit4] Completed [32/785 (1!)] on J0 in 106.06s, 16 tests, 1 failure, 2 skipped <<< FAILURES!
[...truncated 45294 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4517/consoleText
[repro] Revision: ea12b5fd225a6af32cba55e589cdca22e606fc0e
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=TestReplicationHandler -Dtests.method=doTestStopPoll -Dtests.seed=D43BA5FEC8063E6F -Dtests.slow=true -Dtests.locale=uz -Dtests.timezone=Etc/UCT -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestReplicationHandler
[repro] ant compile-test
[...truncated 3322 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestReplicationHandler" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseG1GC" -Dtests.seed=D43BA5FEC8063E6F -Dtests.slow=true -Dtests.locale=uz -Dtests.timezone=Etc/UCT -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 148 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.handler.TestReplicationHandler
[repro] Exiting with code 0
[...truncated 70 lines...]
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk1.8.0) - Build # 4518
- Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4518/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeWithMultipleReplicasLost
Error Message:
The operations computed by ComputePlanAction should not be null {AFTER_ACTION=[compute_plan, null], BEFORE_ACTION=[compute_plan, null]} event: { "id":"31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i", "source":"node_lost_trigger", "eventTime":873310445922196, "eventType":"NODELOST", "properties":{ "eventTimes":[873310445922196], "_enqueue_time_":873322324433846, "nodeNames":["127.0.0.1:10008_solr"]}}
Stack Trace:
java.lang.AssertionError: The operations computed by ComputePlanAction should not be null {AFTER_ACTION=[compute_plan, null], BEFORE_ACTION=[compute_plan, null]}
event: {
"id":"31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i",
"source":"node_lost_trigger",
"eventTime":873310445922196,
"eventType":"NODELOST",
"properties":{
"eventTimes":[873310445922196],
"_enqueue_time_":873322324433846,
"nodeNames":["127.0.0.1:10008_solr"]}}
at __randomizedtesting.SeedInfo.seed([4BE996DD454D339A:7B29775FCD3FD2C6]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNotNull(Assert.java:526)
at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeWithMultipleReplicasLost(TestComputePlanAction.java:240)
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 1841 lines...]
[junit4] JVM J0: stdout was not empty, see: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/lucene/build/core/test/temp/junit4-J0-20180323_022835_263993294050207131487.sysout
[junit4] >>> JVM J0 emitted unexpected output (verbatim) ----
[junit4] codec: FastDecompressionCompressingStoredFields, pf: Memory, dvf: Asserting
[junit4] <<< JVM J0: EOF ----
[...truncated 12287 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_4BE996DD454D339A-001/init-core-data-001
[junit4] 2> 3251233 WARN (SUITE-TestComputePlanAction-seed#[4BE996DD454D339A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 3251233 INFO (SUITE-TestComputePlanAction-seed#[4BE996DD454D339A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3251245 INFO (SUITE-TestComputePlanAction-seed#[4BE996DD454D339A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 3251245 INFO (SUITE-TestComputePlanAction-seed#[4BE996DD454D339A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3251276 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3251276 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 3251277 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251277 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 3251277 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 3251278 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAdded
[junit4] 2> 3251278 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 3251278 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3251278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 3251278 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 3251279 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3251279 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251279 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:165)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3251280 DEBUG (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3251281 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3251281 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 3251281 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251281 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 3251281 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 3251282 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251282 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3251282 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251304 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251329 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251354 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251375 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251385 DEBUG (simCloudManagerPool-10445-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251385 DEBUG (simCloudManagerPool-10445-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3251386 DEBUG (simCloudManagerPool-10445-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3251386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251386 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3251387 DEBUG (simCloudManagerPool-10445-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251387 DEBUG (simCloudManagerPool-10445-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3251387 DEBUG (simCloudManagerPool-10445-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251387 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3251387 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251387 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3251396 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251416 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251438 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251461 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251486 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251511 DEBUG (simCloudManagerPool-10445-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251511 DEBUG (simCloudManagerPool-10445-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 3251511 DEBUG (simCloudManagerPool-10445-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251511 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251512 DEBUG (simCloudManagerPool-10445-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251512 DEBUG (simCloudManagerPool-10445-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 3251513 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 3251513 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 3251513 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3251513 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3251520 DEBUG (simCloudManagerPool-10445-thread-4) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251520 DEBUG (simCloudManagerPool-10445-thread-4) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 3251520 DEBUG (simCloudManagerPool-10445-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251521 DEBUG (simCloudManagerPool-10445-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251521 DEBUG (simCloudManagerPool-10445-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 3251521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 3251521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 3251522 DEBUG (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeAdded
[junit4] 2> 3251533 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251533 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3251533 DEBUG (ScheduledTrigger-10446-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3251543 WARN (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection testNodeAdded is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 3251543 DEBUG (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3251543 DEBUG (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3251543 INFO (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873276851 sessionWrapper.createTime 873276840432446, this.sessionWrapper.createTime 873276840432446
[junit4] 2> 3251543 DEBUG (simCloudManagerPool-10445-thread-5) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3251559 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251559 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3251560 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 3251576 DEBUG (simCloudManagerPool-10445-thread-8) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251576 DEBUG (simCloudManagerPool-10445-thread-8) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 3251576 DEBUG (simCloudManagerPool-10445-thread-8) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251578 DEBUG (simCloudManagerPool-10445-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10005_solr]
[junit4] 2> 3251578 DEBUG (simCloudManagerPool-10445-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=compute_plan, class=solr.ComputePlanAction}, {name=test, class=org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction$AssertingTriggerAction}], enabled=true}
[junit4] 2> 3251578 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 3251578 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 3251582 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3251583 DEBUG (ScheduledTrigger-10446-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251583 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3251583 DEBUG (ScheduledTrigger-10446-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10006_solr at time 873278838408246
[junit4] 2> 3251603 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251603 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 3251603 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 3251603 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [873278838408246], now=873279850827296
[junit4] 2> 3251603 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"31a3e12f40436T5qdm1omq06vll1xv5jm0n5x48",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":873278838408246,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873278838408246],
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 3251604 DEBUG (ScheduledTrigger-10446-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_added_trigger]
[junit4] 2> 3251605 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"31a3e12f40436T5qdm1omq06vll1xv5jm0n5x48",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":873278838408246,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873278838408246],
[junit4] 2> "_enqueue_time_":873279884390146,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}}
[junit4] 2> 3251606 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"31a3e12f40436T5qdm1omq06vll1xv5jm0n5x48",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":873278838408246,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873278838408246],
[junit4] 2> "_enqueue_time_":873279884390146,
[junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 3251606 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3251606 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3251607 INFO (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeAdded&targetNode=127.0.0.1:10006_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 3251607 INFO (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873280023 sessionWrapper.createTime 873280008824696, this.sessionWrapper.createTime 873280008824696
[junit4] 2> 3251607 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3251619 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction Node values: {
[junit4] 2> "127.0.0.1:10006_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":0,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1000,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10006_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10006,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10005_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10005_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10005,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 3251619 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction Live nodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr], collection state: DocCollection(testNodeAdded//clusterstate.json/1)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10006_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":0,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1000,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10006_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10006,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10005_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10005_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10005,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10006_solr, 127.0.0.1:10005_solr]
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeAdded state: DocCollection(testNodeAdded//clusterstate.json/1)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "core":"testNodeAdded_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAdded
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 2
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 1
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testNodeAdded]
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 2
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeAdded 2
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 2
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3251620 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 3251621 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 5
[junit4] 2> 3251621 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 3251621 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3251622 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
[junit4] 2> 3251623 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - BEFORE_ACTION 1
[junit4] 2> 3251623 INFO (TEST-TestComputePlanAction.testNodeAdded-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3251628 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3251628 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 3251628 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 3251628 DEBUG (AutoscalingActionExecutor-10447-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1132 ms for event id=31a3e12f40436T5qdm1omq06vll1xv5jm0n5x48
[junit4] 2> 3251636 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLost
[junit4] 2> 3251636 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 3251636 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 3251637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3251637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251637 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 3251642 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3251642 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3251642 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3251648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3251648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 3251649 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3251649 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion -1
[junit4] 2> 3251649 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 3251650 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251650 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 3251650 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251673 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251695 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251716 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251738 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251759 DEBUG (simCloudManagerPool-10448-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251759 DEBUG (simCloudManagerPool-10448-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 3251759 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251760 DEBUG (simCloudManagerPool-10448-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3251760 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 3251760 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251760 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 3251761 DEBUG (simCloudManagerPool-10448-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251761 DEBUG (simCloudManagerPool-10448-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
[junit4] 2> 3251761 DEBUG (simCloudManagerPool-10448-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3251762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
[junit4] 2> 3251762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251762 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 3251784 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251805 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251827 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251851 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3251871 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251872 DEBUG (simCloudManagerPool-10448-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3251872 DEBUG (simCloudManagerPool-10448-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
[junit4] 2> 3251872 DEBUG (simCloudManagerPool-10448-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10007_solr]
[junit4] 2> 3251872 DEBUG (simCloudManagerPool-10448-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10007_solr]
[junit4] 2> 3251873 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
[junit4] 2> 3251873 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3251873 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 3251873 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3251875 DEBUG (simCloudManagerPool-10448-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeLost
[junit4] 2> 3251895 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251895 DEBUG (simCloudManagerPool-10448-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3251895 DEBUG (simCloudManagerPool-10448-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3251901 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3251901 INFO (simCloudManagerPool-10448-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873294749 sessionWrapper.createTime 873294463483346, this.sessionWrapper.createTime 873294463483346
[junit4] 2> 3251901 DEBUG (simCloudManagerPool-10448-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3251926 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251926 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3251927 DEBUG (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 5
[junit4] 2> live nodes:[127.0.0.1:10006_solr, 127.0.0.1:10007_solr]
[junit4] 2> collections:{testNodeLost=DocCollection(testNodeLost//clusterstate.json/4)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 3251929 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction Stopped_node : 127.0.0.1:10007_solr
[junit4] 2> 3251934 DEBUG (simCloudManagerPool-10448-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeLost / shard1: {"core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeLost"}}
[junit4] 2> 3251947 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251947 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10007_solr
[junit4] 2> 3251947 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3251947 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10007_solr
[junit4] 2> 3251983 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3251983 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252003 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3252003 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252025 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3252025 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252048 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3252048 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252069 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3252069 DEBUG (ScheduledTrigger-10449-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252091 DEBUG (ScheduledTrigger-10449-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 3252091 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2
[junit4] 2> 3252092 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10007_solr]
[junit4] 2> 3252092 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"31a424fd5f6d0T5qdm1omq06vll1xv5jm0n5x4d",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873297039718096,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873297039718096],
[junit4] 2> "nodeNames":["127.0.0.1:10007_solr"]}}
[junit4] 2> 3252093 DEBUG (ScheduledTrigger-10449-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 3252096 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"31a424fd5f6d0T5qdm1omq06vll1xv5jm0n5x4d",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873297039718096,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873297039718096],
[junit4] 2> "_enqueue_time_":873304339638196,
[junit4] 2> "nodeNames":["127.0.0.1:10007_solr"]}}
[junit4] 2> 3252096 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"31a424fd5f6d0T5qdm1omq06vll1xv5jm0n5x4d",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873297039718096,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873297039718096],
[junit4] 2> "_enqueue_time_":873304339638196,
[junit4] 2> "nodeNames":["127.0.0.1:10007_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 3252096 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3252097 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3252100 INFO (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testNodeLost&targetNode=127.0.0.1:10008_solr&inPlaceMove=true&replica=core_node1
[junit4] 2> 3252100 INFO (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873304685 sessionWrapper.createTime 873304561370896, this.sessionWrapper.createTime 873304561370896
[junit4] 2> 3252100 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3252103 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 3252105 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10006_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10006_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10006,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10008_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":0,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":1000,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10008_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10008,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10007_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10007_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10007,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 3252106 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10006_solr]
[junit4] 2> 3252106 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeLost state: DocCollection(testNodeLost//clusterstate.json/6)={
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"2",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10007_solr",
[junit4] 2> "core":"testNodeLost_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testNodeLost_shard1_replica_n2",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"}},
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLost
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 1
[junit4] 2> 3252107 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 2
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10007_solr
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10008_solr
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testNodeLost]
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 1
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 1
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 1
[junit4] 2> 3252108 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeLost 1
[junit4] 2> 3252110 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 1
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3252110 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 3252110 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 3
[junit4] 2> 3252110 DEBUG (AutoscalingActionExecutor-10450-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 726 ms for event id=31a424fd5f6d0T5qdm1omq06vll1xv5jm0n5x4d
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - AFTER_ACTION 1
[junit4] 2> 3252110 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - BEFORE_ACTION 1
[junit4] 2> 3252111 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3252111 INFO (TEST-TestComputePlanAction.testNodeLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 3252211 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeWithMultipleReplicasLost
[junit4] 2> 3252211 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
[junit4] 2> 3252211 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252211 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10008_solr
[junit4] 2> 3252212 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 1
[junit4] 2> 3252212 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10008_solr
[junit4] 2> 3252212 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10007_solr
[junit4] 2> 3252212 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
[junit4] 2> 3252212 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3252212 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3252212 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3252212 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3252213 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:165)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3252215 DEBUG (ScheduledTrigger-10449-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10008_solr
[junit4] 2> 3252221 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 3252222 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
[junit4] 2> 3252223 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3252223 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1
[junit4] 2> 3252223 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
[junit4] 2> 3252223 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3252224 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
[junit4] 2> 3252230 DEBUG (ScheduledTrigger-10452-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252256 DEBUG (ScheduledTrigger-10452-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252277 DEBUG (ScheduledTrigger-10452-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252298 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252319 DEBUG (ScheduledTrigger-10452-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252328 DEBUG (simCloudManagerPool-10451-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3252328 DEBUG (simCloudManagerPool-10451-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
[junit4] 2> 3252329 DEBUG (simCloudManagerPool-10451-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3252329 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
[junit4] 2> 3252330 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3252330 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
[junit4] 2> 3252333 DEBUG (simCloudManagerPool-10451-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3252333 DEBUG (simCloudManagerPool-10451-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16
[junit4] 2> 3252334 DEBUG (simCloudManagerPool-10451-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr]
[junit4] 2> 3252334 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16
[junit4] 2> 3252334 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3252334 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16
[junit4] 2> 3252342 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252363 DEBUG (ScheduledTrigger-10452-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252387 DEBUG (ScheduledTrigger-10452-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252415 DEBUG (ScheduledTrigger-10452-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252435 DEBUG (ScheduledTrigger-10452-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 3252449 DEBUG (simCloudManagerPool-10451-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3252449 DEBUG (simCloudManagerPool-10451-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17
[junit4] 2> 3252449 DEBUG (simCloudManagerPool-10451-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10009_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3252450 DEBUG (simCloudManagerPool-10451-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10009_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3252450 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17
[junit4] 2> 3252450 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3252450 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 17, lastZnodeVersion 17
[junit4] 2> 3252451 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 4
[junit4] 2> 3252451 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10008_solr]
[junit4] 2> 3252452 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873310445922196,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873310445922196],
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] 2> 3252452 DEBUG (simCloudManagerPool-10451-thread-4) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: testNodeWithMultipleReplicasLost
[junit4] 2> 3252453 DEBUG (ScheduledTrigger-10452-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance, node_lost_trigger]
[junit4] 2> 3252456 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873310445922196,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873310445922196],
[junit4] 2> "_enqueue_time_":873322324433846,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] 2> 3252456 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":873310445922196,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[873310445922196],
[junit4] 2> "_enqueue_time_":873322324433846,
[junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 3252456 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3252456 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3252456 INFO (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873322507 sessionWrapper.createTime 873322496133496, this.sessionWrapper.createTime 873322496133496
[junit4] 2> 3252456 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3252462 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 3252462 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 3252462 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger after 100ms
[junit4] 2> 3252462 DEBUG (AutoscalingActionExecutor-10453-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 337 ms for event id=31a456ee86794T5qdm1omq06vll1xv5jm0n5x4i
[junit4] 2> 3252466 DEBUG (simCloudManagerPool-10451-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper Creating a new session
[junit4] 2> 3252466 DEBUG (simCloudManagerPool-10451-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper New session created
[junit4] 2> 3252468 INFO (simCloudManagerPool-10451-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 873323064 sessionWrapper.createTime 873322980514846, this.sessionWrapper.createTime 873322980514846
[junit4] 2> 3252468 DEBUG (simCloudManagerPool-10451-thread-4) [ ] o.a.s.c.s.c.a.PolicyHelper session set to NULL
[junit4] 2> 3252537 DEBUG (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction -- cluster state: znodeVersion: 11
[junit4] 2> live nodes:[127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10009_solr, 127.0.0.1:10011_solr]
[junit4] 2> collections:{testNodeWithMultipleReplicasLost=DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/10)={
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "node_name":"127.0.0.1:10009_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node4":{
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node5":{
[junit4] 2> "node_name":"127.0.0.1:10010_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10011_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10009_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node3":{
[junit4] 2> "node_name":"127.0.0.1:10010_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}}
[junit4] 2> 3252541 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction -------------_ FINAL STATE --------------
[junit4] 2> 3252541 DEBUG (simCloudManagerPool-10451-thread-15) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard2: {"core_node6":{
[junit4] 2> "node_name":"127.0.0.1:10009_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}}
[junit4] 2> 3252541 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Node values: {
[junit4] 2> "127.0.0.1:10006_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10006_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10006,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10010_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10010_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10010,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10009_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":2,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":998,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10009_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10009,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0},
[junit4] 2> "127.0.0.1:10011_solr":{
[junit4] 2> "sysprop.java.vendor":"Oracle Corporation",
[junit4] 2> "cores":1,
[junit4] 2> "host":"127.0.0.1",
[junit4] 2> "freedisk":999,
[junit4] 2> "sysprop.java.version":"1.8.0_144",
[junit4] 2> "ip_1":"127",
[junit4] 2> "ip_3":"0",
[junit4] 2> "ip_2":"0",
[junit4] 2> "ip_4":"1",
[junit4] 2> "node":"127.0.0.1:10011_solr",
[junit4] 2> "metrics:solr.jvm:buffers.direct.Count":0,
[junit4] 2> "port":10011,
[junit4] 2> "heapUsage":123450000,
[junit4] 2> "sysLoadAvg":1.0,
[junit4] 2> "metrics:solr.node:ADMIN./admin/authorization.clientErrors:count":0}}
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Live nodes: [127.0.0.1:10006_solr, 127.0.0.1:10009_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3252541 DEBUG (simCloudManagerPool-10451-thread-16) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testNodeWithMultipleReplicasLost / shard1: {"core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10011_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testNodeWithMultipleReplicasLost"}}
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.TestComputePlanAction * Collection testNodeWithMultipleReplicasLost state: DocCollection(testNodeWithMultipleReplicasLost//clusterstate.json/12)={
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "autoCreated":"true",
[junit4] 2> "shards":{
[junit4] 2> "shard2":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node6":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n6",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10009_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node4":{
[junit4] 2> "node_name":"127.0.0.1:10006_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n4",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node5":{
[junit4] 2> "node_name":"127.0.0.1:10010_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard2_replica_n5",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10011_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node2":{
[junit4] 2> "node_name":"127.0.0.1:10009_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n2",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1},
[junit4] 2> "core_node3":{
[junit4] 2> "node_name":"127.0.0.1:10010_solr",
[junit4] 2> "core":"testNodeWithMultipleReplicasLost_shard1_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":1}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeWithMultipleReplicasLost
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 3252542 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 0
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## 127.0.0.1:10010_solr
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: [testNodeWithMultipleReplicasLost]
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 2
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 4
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeWithMultipleReplicasLost 4
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 4
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 3
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 4
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_lost_trigger
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - AFTER_ACTION 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - BEFORE_ACTION 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 3252543 INFO (TEST-TestComputePlanAction.testNodeWithMultipleReplicasLost-seed#[4BE996DD454D339A]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeWithMultipleReplicasLost -Dtests.seed=4BE996DD454D339A -Dtests.slow=true -Dtests.locale=ar -Dtests.timezone=Asia/Irkutsk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 0.44s J1 | TestComputePlanAction.tes
[...truncated too long message...]
"nodeNames":["127.0.0.1:10008_solr"]}}
[junit4] > at __randomizedtesting.SeedInfo.seed([4BE996DD454D339A:7B29775FCD3FD2C6]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction.testNodeWithMultipleReplicasLost(TestComputePlanAction.java:240)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3252557 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3252558 DEBUG (SUITE-TestComputePlanAction-seed#[4BE996DD454D339A]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestComputePlanAction_4BE996DD454D339A-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=485, maxMBSortInHeap=5.696187596170809, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@3145ef3), locale=ar, timezone=Asia/Irkutsk
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=184502472,total=520093696
[junit4] 2> NOTE: All tests run in this JVM: [TestFuzzyAnalyzedSuggestions, SpellPossibilityIteratorTest, RegexBoostProcessorTest, ResponseHeaderTest, LoggingHandlerTest, TestStressRecovery, TestZkAclsWithHadoopAuth, TestCollectionAPI, TestSolrConfigHandler, BasicFunctionalityTest, SliceStateTest, TestCollectionAPIs, NoCacheHeaderTest, ConfigureRecoveryStrategyTest, TestInPlaceUpdatesStandalone, ChaosMonkeySafeLeaderTest, TestQueryWrapperFilter, TestBadConfig, TestSolrCoreProperties, TestStressReorder, RankQueryTest, AddBlockUpdateTest, TestStressCloudBlindAtomicUpdates, TestLockTree, TestSolrQueryParser, CdcrReplicationDistributedZkTest, PeerSyncReplicationTest, TestCloudDeleteByQuery, TimeZoneUtilsTest, TestPolicyCloud, TestConfigReload, TestMultiValuedNumericRangeQuery, SolrMetricManagerTest, BadIndexSchemaTest, LargeFieldTest, TestTrackingShardHandlerFactory, TestRandomFaceting, TestSolrCloudSnapshots, TestHdfsBackupRestoreCore, TestLegacyFieldCache, TestSearchPerf, BJQParserTest, TestFilteredDocIdSet, TestDistributedMap, DistributedSuggestComponentTest, TestComplexPhraseLeadingWildcard, SortByFunctionTest, BlockJoinFacetRandomTest, QueryParsingTest, BlockCacheTest, TestOrdValues, SolrJmxReporterTest, ShardRoutingTest, TestConfig, NodeMutatorTest, TestReplicaProperties, HdfsUnloadDistributedZkTest, IndexBasedSpellCheckerTest, TestStressLucene, DefaultValueUpdateProcessorTest, SearchRateTriggerTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, MoveReplicaHDFSFailoverTest, ExternalFileFieldSortTest, HdfsRestartWhileUpdatingTest, TestShardHandlerFactory, TestAnalyzedSuggestions, TestFreeTextSuggestions, TestConfigSets, TestRawResponseWriter, TestWriterPerf, CircularListTest, SuggestComponentContextFilterQueryTest, SolrGraphiteReporterTest, EchoParamsTest, TestRandomFlRTGCloud, TestNonDefinedSimilarityFactory, AddReplicaTest, TestRTGBase, MetricsConfigTest, TestStressLiveNodes, TestUpdate, RestartWhileUpdatingTest, DisMaxRequestHandlerTest, TestNRTOpen, TestComponentsName, AnalyticsMergeStrategyTest, CurrencyRangeFacetCloudTest, TestConfigSetsAPIZkFailure, TestDocSet, VersionInfoTest, GraphQueryTest, CSVRequestHandlerTest, InfixSuggestersTest, HdfsLockFactoryTest, TestCodecSupport, StressHdfsTest, TestOnReconnectListenerSupport, TestCrossCoreJoin, TestRecoveryHdfs, TestSQLHandler, PKIAuthenticationIntegrationTest, TestLegacyNumericRangeQueryBuilder, TestDocBasedVersionConstraints, AutoScalingHandlerTest, HdfsBasicDistributedZkTest, TestCustomDocTransformer, SecurityConfHandlerTest, ParsingFieldUpdateProcessorsTest, TestSimpleTrackingShardHandler, TestSlowCompositeReaderWrapper, HighlighterConfigTest, TestPointFields, TolerantUpdateProcessorTest, TestPolicyCloud, SuggesterTest, TestLuceneMatchVersion, V2StandaloneTest, TestHashPartitioner, DistanceFunctionTest, TestUniqueKeyFieldResource, TestMacros, CdcrUpdateLogTest, SharedFSAutoReplicaFailoverTest, AssignBackwardCompatibilityTest, DocValuesTest, MoveReplicaTest, PreAnalyzedFieldManagedSchemaCloudTest, SimplePostToolTest, TestSmileRequest, TestValueSourceCache, OverseerStatusTest, TestReqParamsAPI, PeerSyncWithIndexFingerprintCachingTest, LeaderVoteWaitTimeoutTest, TestXmlQParserPlugin, DirectUpdateHandlerTest, TestSearcherReuse, TestAddFieldRealTimeGet, HdfsDirectoryFactoryTest, TestFastWriter, TestDeleteCollectionOnDownNodes, TestIndexingPerformance, BasicDistributedZk2Test, TestNamedUpdateProcessors, TestRetrieveFieldsOptimizer, MinimalSchemaTest, TestRebalanceLeaders, TestGeoJSONResponseWriter, TestUtilizeNode, ShowFileRequestHandlerTest, LeaderFailoverAfterPartitionTest, JsonLoaderTest, TestTolerantUpdateProcessorCloud, ConnectionManagerTest, TestSolrCoreParser, IndexSchemaTest, UpdateRequestProcessorFactoryTest, CoreAdminCreateDiscoverTest, ExecutePlanActionTest, HttpPartitionTest, NotRequiredUniqueKeyTest, TestExtendedDismaxParser, TermVectorComponentTest, TestPayloadCheckQParserPlugin, TestAtomicUpdateErrorCases, OverseerModifyCollectionTest, ZkSolrClientTest, OverriddenZkACLAndCredentialsProvidersTest, DeleteLastCustomShardedReplicaTest, ScriptEngineTest, TestAuthenticationFramework, ImplicitSnitchTest, SpellCheckCollatorTest, SystemInfoHandlerTest, SpellCheckComponentTest, TestSolrConfigHandlerCloud, TestShortCircuitedRequests, ClassificationUpdateProcessorTest, TestHttpShardHandlerFactory, ZkControllerTest, SmileWriterTest, NodeAddedTriggerTest, SearchHandlerTest, TestNumericTerms64, ChaosMonkeyNothingIsSafeTest, BasicDistributedZkTest, TestRealTimeGet, TestJoin, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, SolrCmdDistributorTest, TestSort, TestFunctionQuery, TestLazyCores, TestCoreDiscovery, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, CoreAdminHandlerTest, TestFoldingMultitermQuery, TestTrie, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, SolrCoreCheckLockOnStartupTest, TestPseudoReturnFields, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, StatelessScriptUpdateProcessorFactoryTest, DocValuesMultiTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, DebugComponentTest, TestSurroundQueryParser, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, TestQueryTypes, PrimitiveFieldTypeTest, TestOmitPositions, FileBasedSpellCheckerTest, TermsComponentTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, TestJmxIntegration, TestCollationField, ReturnFieldsTest, TestCSVResponseWriter, MBeansHandlerTest, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, SearchHandlerTest, TestLFUCache, TestSolrDeletionPolicy2, TestElisionMultitermQuery, TestPostingsSolrHighlighter, SynonymTokenizerTest, TestDFRSimilarityFactory, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, ResourceLoaderTest, PluginInfoTest, TestFastLRUCache, DateMathParserTest, TestSystemIdResolver, PrimUtilsTest, DateFieldTest, DOMUtilTest, ClusterStateTest, TestLRUCache, TestDocumentBuilder, FileUtilsTest, CursorPagingTest, TestDistributedMissingSort, ConnectionReuseTest, CleanupOldIndexTest, CollectionsAPISolrJTest, DeleteNodeTest, DeleteReplicaTest, DistribDocExpirationUpdateProcessorTest, DocValuesNotIndexedTest, HealthCheckHandlerTest, HttpPartitionOnCommitTest, LeaderElectionContextKeyTest, LegacyCloudClusterPropTest, MigrateRouteKeyTest, OverseerCollectionConfigSetProcessorTest, RemoteQueryErrorTest, ReplaceNodeNoTargetTest, ReplaceNodeTest, SSLMigrationTest, SolrCloudExampleTest, TestCloudPseudoReturnFields, TestCloudRecovery, TestClusterProperties, TestConfigSetsAPI, TestExclusionRuleCollectionAccess, TestLeaderElectionWithEmptyReplica, TestRandomRequestDistribution, TestRequestForwarding, TestSSLRandomization, TestSizeLimitedDistributedMap, TestSkipOverseerOperations, TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorRandomCloud, TriLevelCompositeIdRoutingTest, VMParamsZkACLAndCredentialsProvidersTest, ZkFailoverTest, CollectionTooManyReplicasTest, CollectionsAPIDistributedZkTest, TestHdfsCloudBackupRestore, AutoAddReplicasIntegrationTest, ComputePlanActionTest, HttpTriggerListenerTest, NodeLostTriggerTest, SystemLogListenerTest, TestClusterStateProvider, TestComputePlanAction]
[junit4] Completed [596/785 (1!)] on J1 in 1.36s, 3 tests, 1 failure <<< FAILURES!
[...truncated 50161 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4518/consoleText
[repro] Revision: ea12b5fd225a6af32cba55e589cdca22e606fc0e
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=TestComputePlanAction -Dtests.method=testNodeWithMultipleReplicasLost -Dtests.seed=4BE996DD454D339A -Dtests.slow=true -Dtests.locale=ar -Dtests.timezone=Asia/Irkutsk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestComputePlanAction
[repro] ant compile-test
[...truncated 3317 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestComputePlanAction" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=4BE996DD454D339A -Dtests.slow=true -Dtests.locale=ar -Dtests.timezone=Asia/Irkutsk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 78 lines...]
[repro] Failures:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestComputePlanAction
[repro] Exiting with code 0
[...truncated 70 lines...]