Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-MacOSX/810/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

1 tests failed.
FAILED:  org.apache.solr.cloud.ShardSplitTest.testSplitWithChaosMonkey

Error Message:
There are still nodes recoverying - waited for 330 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 330 
seconds
        at 
__randomizedtesting.SeedInfo.seed([98AF0DB26789CB34:1388DE63268F60B0]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at 
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:187)
        at 
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:144)
        at 
org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:139)
        at 
org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:865)
        at 
org.apache.solr.cloud.ShardSplitTest.testSplitWithChaosMonkey(ShardSplitTest.java:437)
        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:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
        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:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        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:745)




Build Log:
[...truncated 12646 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/init-core-data-001
   [junit4]   2> 3066128 INFO  
(SUITE-ShardSplitTest-seed#[98AF0DB26789CB34]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields
   [junit4]   2> 3066133 INFO  
(SUITE-ShardSplitTest-seed#[98AF0DB26789CB34]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776)
 w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 3066133 INFO  
(SUITE-ShardSplitTest-seed#[98AF0DB26789CB34]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_/av
   [junit4]   2> 3066135 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3066135 INFO  (Thread-3638) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3066135 INFO  (Thread-3638) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3066245 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkTestServer start zk server on port:52657
   [junit4]   2> 3066308 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml
 to /configs/conf1/solrconfig.xml
   [junit4]   2> 3066320 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml
 to /configs/conf1/schema.xml
   [junit4]   2> 3066348 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml
 to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3066357 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt
 to /configs/conf1/stopwords.txt
   [junit4]   2> 3066375 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt
 to /configs/conf1/protwords.txt
   [junit4]   2> 3066379 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml
 to /configs/conf1/currency.xml
   [junit4]   2> 3066383 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml
 to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3066386 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json
 to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3066390 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt
 to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3066394 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt
 to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3066398 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractZkTestCase put 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt
 to /configs/conf1/synonyms.txt
   [junit4]   2> 3067963 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/cores/collection1
   [junit4]   2> 3067971 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3067975 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@64d05417{/_/av,null,AVAILABLE}
   [junit4]   2> 3067975 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@6a01d9f0{HTTP/1.1,[http/1.1]}{127.0.0.1:52661}
   [junit4]   2> 3067975 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server Started @3073749ms
   [junit4]   2> 3067977 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/tempDir-001/control/data,
 hostContext=/_/av, hostPort=52661, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/cores}
   [junit4]   2> 3067978 ERROR 
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3067978 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3067978 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3067978 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3067978 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-04-06T14:56:15.743Z
   [junit4]   2> 3067985 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3067985 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/solr.xml
   [junit4]   2> 3068019 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3068020 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52657/solr
   [junit4]   2> 3068073 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3068075 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:52661__%2Fav
   [junit4]   2> 3068077 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.Overseer Overseer 
(id=97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) starting
   [junit4]   2> 3068092 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52661__%2Fav
   [junit4]   2> 3068098 INFO  
(zkCallback-3725-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3068408 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/cores
   [junit4]   2> 3068409 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3068411 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3068415 INFO  
(OverseerStateUpdate-97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 3069449 WARN  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3069451 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3069477 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 3069590 WARN  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 3069592 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 3069625 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
collection control_collection, trusted=true
   [junit4]   2> 3069642 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 3069642 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/control-001/cores/collection1/data/]
   [junit4]   2> 3069642 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@368968e3
   [junit4]   2> 3069647 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=41.5087890625, 
floorSegmentMB=2.0576171875, forceMergeDeletesPctAllowed=26.659418401712355, 
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3069700 WARN  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3070024 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 3070024 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3070026 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 3070026 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 3070027 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.18887893386334326]
   [junit4]   2> 3070046 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@6185fe73[collection1] main]
   [junit4]   2> 3070050 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3070052 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3070053 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3070055 INFO  
(searcherExecutor-7786-thread-1-processing-n:127.0.0.1:52661__%2Fav 
x:collection1 c:control_collection) [n:127.0.0.1:52661__%2Fav 
c:control_collection   x:collection1] o.a.s.c.SolrCore [collection1] Registered 
new searcher Searcher@6185fe73[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3070055 INFO  
(coreLoadExecutor-7785-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav c:control_collection   x:collection1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1563941224128184320
   [junit4]   2> 3070069 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas 
found to continue.
   [junit4]   2> 3070069 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new 
leader - try and sync
   [junit4]   2> 3070069 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:52661/_/av/collection1/
   [junit4]   2> 3070070 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync 
replicas to me
   [junit4]   2> 3070070 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.SyncStrategy 
http://127.0.0.1:52661/_/av/collection1/ has no replicas
   [junit4]   2> 3070070 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Found all 
replicas participating in election, clear LIR
   [junit4]   2> 3070080 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new 
leader: http://127.0.0.1:52661/_/av/collection1/ shard1
   [junit4]   2> 3070138 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 3070140 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:52657/solr ready
   [junit4]   2> 3070141 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection 
loss:false
   [junit4]   2> 3070237 INFO  
(coreZkRegister-7778-thread-1-processing-n:127.0.0.1:52661__%2Fav x:collection1 
c:control_collection) [n:127.0.0.1:52661__%2Fav c:control_collection s:shard1 
r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery 
necessary
   [junit4]   2> 3070646 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/cores/collection1
   [junit4]   2> 3070648 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001
   [junit4]   2> 3070649 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3070653 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@120b3262{/_/av,null,AVAILABLE}
   [junit4]   2> 3070654 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@19e0aaa{HTTP/1.1,[http/1.1]}{127.0.0.1:52670}
   [junit4]   2> 3070654 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server Started @3076428ms
   [junit4]   2> 3070654 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/tempDir-001/jetty1,
 solrconfig=solrconfig.xml, hostContext=/_/av, hostPort=52670, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/cores}
   [junit4]   2> 3070655 ERROR 
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3070658 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3070658 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3070658 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3070658 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-04-06T14:56:18.423Z
   [junit4]   2> 3070665 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3070665 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/solr.xml
   [junit4]   2> 3070699 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3070700 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52657/solr
   [junit4]   2> 3070725 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3070737 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3070745 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52670__%2Fav
   [junit4]   2> 3070753 INFO  
(zkCallback-3725-thread-2-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3070762 INFO  
(zkCallback-3734-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3070754 INFO  (zkCallback-3729-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 3070968 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/cores
   [junit4]   2> 3070968 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3070969 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3070971 INFO  
(OverseerStateUpdate-97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard2
   [junit4]   2> 3072013 WARN  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3072015 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3072040 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3072156 WARN  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 3072159 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 3072192 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3072192 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3072193 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-1-001/cores/collection1/data/]
   [junit4]   2> 3072193 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@368968e3
   [junit4]   2> 3072197 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=41.5087890625, 
floorSegmentMB=2.0576171875, forceMergeDeletesPctAllowed=26.659418401712355, 
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3072235 WARN  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3072389 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 3072389 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3072391 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3072391 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3072392 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.18887893386334326]
   [junit4]   2> 3072393 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@19716d1d[collection1] main]
   [junit4]   2> 3072396 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3072397 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3072397 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3072400 INFO  
(searcherExecutor-7797-thread-1-processing-n:127.0.0.1:52670__%2Fav 
x:collection1 c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@19716d1d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3072401 INFO  
(coreLoadExecutor-7796-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1563941226588143616
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to 
continue.
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try 
and sync
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:52670/_/av/collection1/
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:52670/_/av/collection1/ 
has no replicas
   [junit4]   2> 3072420 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas 
participating in election, clear LIR
   [junit4]   2> 3072431 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:52670/_/av/collection1/ shard2
   [junit4]   2> 3072599 INFO  
(coreZkRegister-7791-thread-1-processing-n:127.0.0.1:52670__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52670__%2Fav c:collection1 s:shard2 r:core_node1 
x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 3073140 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/cores/collection1
   [junit4]   2> 3073142 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001
   [junit4]   2> 3073142 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3073145 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@56d82edc{/_/av,null,AVAILABLE}
   [junit4]   2> 3073146 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@711b6be6{HTTP/1.1,[http/1.1]}{127.0.0.1:52680}
   [junit4]   2> 3073146 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server Started @3078920ms
   [junit4]   2> 3073147 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/tempDir-001/jetty2,
 solrconfig=solrconfig.xml, hostContext=/_/av, hostPort=52680, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/cores}
   [junit4]   2> 3073147 ERROR 
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3073148 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3073148 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3073148 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3073148 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-04-06T14:56:20.913Z
   [junit4]   2> 3073153 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3073153 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/solr.xml
   [junit4]   2> 3073214 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3073215 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52657/solr
   [junit4]   2> 3073236 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3073244 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3073249 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52680__%2Fav
   [junit4]   2> 3073253 INFO  
(zkCallback-3734-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3073253 INFO  (zkCallback-3729-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3073256 INFO  
(zkCallback-3740-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3073256 INFO  
(zkCallback-3725-thread-3-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3073363 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/cores
   [junit4]   2> 3073363 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3073364 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3073366 INFO  
(OverseerStateUpdate-97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 3074391 WARN  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3074392 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3074407 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3074516 WARN  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 3074517 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 3074551 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3074551 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3074551 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-2-001/cores/collection1/data/]
   [junit4]   2> 3074552 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@368968e3
   [junit4]   2> 3074555 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=41.5087890625, 
floorSegmentMB=2.0576171875, forceMergeDeletesPctAllowed=26.659418401712355, 
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3074604 WARN  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3074724 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 3074724 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3074725 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3074725 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3074725 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.18887893386334326]
   [junit4]   2> 3074726 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@272a0852[collection1] main]
   [junit4]   2> 3074728 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3074729 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3074729 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3074731 INFO  
(searcherExecutor-7808-thread-1-processing-n:127.0.0.1:52680__%2Fav 
x:collection1 c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@272a0852[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3074732 INFO  
(coreLoadExecutor-7807-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1563941229032374272
   [junit4]   2> 3074745 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to 
continue.
   [junit4]   2> 3074745 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try 
and sync
   [junit4]   2> 3074746 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:52680/_/av/collection1/
   [junit4]   2> 3074746 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 3074746 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:52680/_/av/collection1/ 
has no replicas
   [junit4]   2> 3074746 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.ShardLeaderElectionContext Found all replicas 
participating in election, clear LIR
   [junit4]   2> 3074754 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:52680/_/av/collection1/ shard1
   [junit4]   2> 3074912 INFO  
(coreZkRegister-7802-thread-1-processing-n:127.0.0.1:52680__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52680__%2Fav c:collection1 s:shard1 r:core_node2 
x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 3076810 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/cores/collection1
   [junit4]   2> 3076813 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001
   [junit4]   2> 3076814 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3076816 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@3b7a7ece{/_/av,null,AVAILABLE}
   [junit4]   2> 3076817 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@637c3eb8{HTTP/1.1,[http/1.1]}{127.0.0.1:52684}
   [junit4]   2> 3076817 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server Started @3082591ms
   [junit4]   2> 3076817 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/tempDir-001/jetty3,
 solrconfig=solrconfig.xml, hostContext=/_/av, hostPort=52684, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/cores}
   [junit4]   2> 3076819 ERROR 
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3076820 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3076820 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3076820 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3076820 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-04-06T14:56:24.585Z
   [junit4]   2> 3076827 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3076828 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/solr.xml
   [junit4]   2> 3076851 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3076853 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52657/solr
   [junit4]   2> 3076879 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3076888 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3076894 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52684__%2Fav
   [junit4]   2> 3076905 INFO  
(zkCallback-3725-thread-1-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3076905 INFO  (zkCallback-3729-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3076908 INFO  
(zkCallback-3746-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3076906 INFO  
(zkCallback-3740-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3076906 INFO  
(zkCallback-3734-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3077050 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/cores
   [junit4]   2> 3077050 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3077051 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3077056 INFO  
(OverseerStateUpdate-97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard2
   [junit4]   2> 3078084 WARN  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3078085 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3078098 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3078182 WARN  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 3078184 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 3078220 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3078221 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3078221 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-3-001/cores/collection1/data/]
   [junit4]   2> 3078221 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@368968e3
   [junit4]   2> 3078259 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=41.5087890625, 
floorSegmentMB=2.0576171875, forceMergeDeletesPctAllowed=26.659418401712355, 
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3078295 WARN  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3078442 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 3078443 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3078444 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3078444 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3078446 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.18887893386334326]
   [junit4]   2> 3078448 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@4f4b7c3f[collection1] main]
   [junit4]   2> 3078450 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3078451 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3078451 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3078454 INFO  
(searcherExecutor-7819-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 c:collection1) [n:127.0.0.1:52684__%2Fav c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@4f4b7c3f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3078455 INFO  
(coreLoadExecutor-7818-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1563941232936222720
   [junit4]   2> 3078461 INFO  
(coreZkRegister-7813-thread-1-processing-n:127.0.0.1:52684__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52684__%2Fav c:collection1 s:shard2 r:core_node3 
x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 3078462 INFO  
(updateExecutor-3743-thread-1-processing-n:127.0.0.1:52684__%2Fav x:collection1 
s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav c:collection1 
s:shard2 r:core_node3 x:collection1] o.a.s.u.DefaultSolrCoreState Running 
recovery
   [junit4]   2> 3078463 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 3078463 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
###### startupVersions=[[]]
   [junit4]   2> 3078463 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Begin buffering updates. core=[collection1]
   [junit4]   2> 3078463 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.UpdateLog Starting 
to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
   [junit4]   2> 3078463 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Publishing state of core [collection1] as recovering, leader is 
[http://127.0.0.1:52670/_/av/collection1/] and I am 
[http://127.0.0.1:52684/_/av/collection1/]
   [junit4]   2> 3078469 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Sending prep recovery command to [http://127.0.0.1:52670/_/av]; [WaitForState: 
action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:52684__%252Fav&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 3078476 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: 
recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 3078477 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 
(shard2 of collection1) have state: recovering
   [junit4]   2> 3078477 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): 
collection=collection1, shard=shard2, thisCore=collection1, 
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, 
currentState=down, localState=active, nodeName=127.0.0.1:52684__%2Fav, 
coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:52684/_/av","node_name":"127.0.0.1:52684__%2Fav","state":"down"}
   [junit4]   2> 3079475 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/cores/collection1
   [junit4]   2> 3079478 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): 
collection=collection1, shard=shard2, thisCore=collection1, 
leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, 
currentState=recovering, localState=active, nodeName=127.0.0.1:52684__%2Fav, 
coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: 
core_node3:{"core":"collection1","base_url":"http://127.0.0.1:52684/_/av","node_name":"127.0.0.1:52684__%2Fav","state":"recovering"}
   [junit4]   2> 3079478 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: 
recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 3079478 INFO  (qtp1510491737-17429) [n:127.0.0.1:52670__%2Fav  
  ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={nodeName=127.0.0.1:52684__%252Fav&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2}
 status=0 QTime=1002
   [junit4]   2> 3079479 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001
   [junit4]   2> 3079479 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server jetty-9.3.14.v20161028
   [junit4]   2> 3079482 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@346c54c{/_/av,null,AVAILABLE}
   [junit4]   2> 3079483 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4a2f572{HTTP/1.1,[http/1.1]}{127.0.0.1:52689}
   [junit4]   2> 3079483 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.Server Started @3085257ms
   [junit4]   2> 3079484 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: 
{solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/tempDir-001/jetty4,
 solrconfig=solrconfig.xml, hostContext=/_/av, hostPort=52689, 
coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/cores}
   [junit4]   2> 3079484 ERROR 
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3079485 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.6.0
   [junit4]   2> 3079485 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3079485 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3079485 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-04-06T14:56:27.250Z
   [junit4]   2> 3079490 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in 
ZooKeeper)
   [junit4]   2> 3079491 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/solr.xml
   [junit4]   2> 3079529 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 3079531 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:52657/solr
   [junit4]   2> 3079556 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 3079564 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3079570 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:52689__%2Fav
   [junit4]   2> 3079573 INFO  (zkCallback-3729-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
   [junit4]   2> 3079574 INFO  
(zkCallback-3740-thread-1-processing-n:127.0.0.1:52680__%2Fav) 
[n:127.0.0.1:52680__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3079574 INFO  
(zkCallback-3746-thread-1-processing-n:127.0.0.1:52684__%2Fav) 
[n:127.0.0.1:52684__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3079575 INFO  
(zkCallback-3734-thread-1-processing-n:127.0.0.1:52670__%2Fav) 
[n:127.0.0.1:52670__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3079575 INFO  
(zkCallback-3725-thread-2-processing-n:127.0.0.1:52661__%2Fav) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3079577 INFO  
(zkCallback-3753-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3079698 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.CorePropertiesLocator Found 1 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/cores
   [junit4]   2> 3079698 INFO  
(TEST-ShardSplitTest.testSplitWithChaosMonkey-seed#[98AF0DB26789CB34]) 
[n:127.0.0.1:52689__%2Fav    ] o.a.s.c.CorePropertiesLocator Cores are: 
[collection1]
   [junit4]   2> 3079699 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 
transient cores
   [junit4]   2> 3079702 INFO  
(OverseerStateUpdate-97746326251307012-127.0.0.1:52661__%2Fav-n_0000000000) 
[n:127.0.0.1:52661__%2Fav    ] o.a.s.c.o.ReplicaMutator Assigning new node to 
shard shard=shard1
   [junit4]   2> 3079981 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Attempting to PeerSync from [http://127.0.0.1:52670/_/av/collection1/] - 
recoveringAfterStartup=[true]
   [junit4]   2> 3079982 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.PeerSync PeerSync: 
core=collection1 url=http://127.0.0.1:52684/_/av START 
replicas=[http://127.0.0.1:52670/_/av/collection1/] nUpdates=100
   [junit4]   2> 3079988 INFO  (qtp1510491737-17432) [n:127.0.0.1:52670__%2Fav 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.u.IndexFingerprint 
IndexFingerprint millis:1.0 result:{maxVersionSpecified=9223372036854775807, 
maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, 
maxDoc=0}
   [junit4]   2> 3079988 INFO  (qtp1510491737-17432) [n:127.0.0.1:52670__%2Fav 
c:collection1 s:shard2 r:core_node1 x:collection1] o.a.s.c.S.Request 
[collection1]  webapp=/_/av path=/get 
params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2}
 status=0 QTime=2
   [junit4]   2> 3079990 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.IndexFingerprint 
IndexFingerprint millis:1.0 result:{maxVersionSpecified=9223372036854775807, 
maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, 
maxDoc=0}
   [junit4]   2> 3079990 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.PeerSync We are 
already in sync. No need to do a PeerSync 
   [junit4]   2> 3079990 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 3079990 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 3079991 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.u.DirectUpdateHandler2 
end_commit_flush
   [junit4]   2> 3079991 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
PeerSync stage of recovery was successful.
   [junit4]   2> 3079991 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Replaying updates buffered during PeerSync.
   [junit4]   2> 3079991 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy No 
replay needed.
   [junit4]   2> 3079991 INFO  
(recoveryExecutor-3744-thread-1-processing-n:127.0.0.1:52684__%2Fav 
x:collection1 s:shard2 c:collection1 r:core_node3) [n:127.0.0.1:52684__%2Fav 
c:collection1 s:shard2 r:core_node3 x:collection1] o.a.s.c.RecoveryStrategy 
Registering as Active after recovery.
   [junit4]   2> 3080767 WARN  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.c.Config 
Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> 
instead.
   [junit4]   2> 3080768 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.c.SolrConfig 
Using Lucene MatchVersion: 6.6.0
   [junit4]   2> 3080781 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] Schema name=test
   [junit4]   2> 3080884 WARN  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
[collection1] default search field in schema is text. WARNING: Deprecated, 
please use 'df' on request instead.
   [junit4]   2> 3080885 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.s.IndexSchema 
Loaded schema test/1.6 with uniqueid field id
   [junit4]   2> 3080917 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.c.CoreContainer 
Creating SolrCore 'collection1' using configuration from collection 
collection1, trusted=true
   [junit4]   2> 3080917 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
solr.RecoveryStrategy.Builder
   [junit4]   2> 3080917 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.c.SolrCore 
[[collection1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/cores/collection1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001/shard-4-001/cores/collection1/data/]
   [junit4]   2> 3080918 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@368968e3
   [junit4]   2> 3080920 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=41.5087890625, 
floorSegmentMB=2.0576171875, forceMergeDeletesPctAllowed=26.659418401712355, 
segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3080957 WARN  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, class=DumpRequestHandler},args = 
{defaults={a=A,b=B}}}
   [junit4]   2> 3081026 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateHandler 
Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 3081027 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 
maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 3081027 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Hard AutoCommit: disabled
   [junit4]   2> 3081027 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.u.CommitTracker 
Soft AutoCommit: disabled
   [junit4]   2> 3081028 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.18887893386334326]
   [junit4]   2> 3081029 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@4f4303a[collection1] main]
   [junit4]   2> 3081031 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: 
/configs/conf1
   [junit4]   2> 3081032 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using 
ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3081032 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 3081033 INFO  
(searcherExecutor-7830-thread-1-processing-n:127.0.0.1:52689__%2Fav 
x:collection1 c:collection1) [n:127.0.0.1:52689__%2Fav c:collection1   
x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@4f4303a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 3081034 INFO  
(coreLoadExecutor-7829-thread-1-processing-n:127.0.0.1:52689__%2Fav) 
[n:127.0.0.1:52689__%2Fav c:collection1   x:collection1] o.a.s.u.UpdateLog 
Could not find max version in index or recent updates, using new clock 
1563941235640500224
   [junit4]   2> 3081040 INFO  
(coreZkRegister-7824-thread-1-processing-n:127.0.0.1:52689__%2Fav x:collection1 
c:collection1) [n:127.0.0.1:52689__%2Fav c:collection1 s:shard1 r:core_node4 
x:collection1] o.a.s.c.ZkController Core needs to recover:collection1
   [junit4]   2> 3081041 INFO  
(updateExecutor-3750-thread-1-processing-n:127.0.0.1:52689__%2Fav x:collection1 
s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:52689__%2Fav c:collection1 
s:shard1 r:core_node4 x:collection1] o.a.s.u.DefaultSolrCoreState Running 
recovery
   [junit4]   2> 3081042 INFO  
(recoveryExecutor-3751-thread-1-processing-n:127.0.0.1:52689__%2Fav 
x:collection1 s:shard1 c:collection1 r:core_node4) [n:127.0.0.1:52689__%2Fav 
c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.RecoveryStrategy 
Starting recovery process. recoveringAfterStartup=true
   [junit4]   2> 3081042 INFO  (recoveryExecutor-3751-thread-1-pr

[...truncated too long message...]

unit4]   2> 3792868 INFO  
(recoveryExecutor-3939-thread-1-processing-n:127.0.0.1:54124__%2Fav 
x:collection1_shard1_0_replica0 s:shard1_0 c:collection1 r:core_node8) 
[n:127.0.0.1:54124__%2Fav c:collection1 s:shard1_0 r:core_node8 
x:collection1_shard1_0_replica0] o.a.s.c.SolrCore 
[collection1_shard1_0_replica0]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@639dfbca
   [junit4]   2> 3792869 WARN  
(recoveryExecutor-3939-thread-1-processing-n:127.0.0.1:54124__%2Fav 
x:collection1_shard1_0_replica0 s:shard1_0 c:collection1 r:core_node8) 
[n:127.0.0.1:54124__%2Fav c:collection1 s:shard1_0 r:core_node8 
x:collection1_shard1_0_replica0] o.a.s.c.RecoveryStrategy Stopping recovery for 
core=[collection1_shard1_0_replica0] coreNodeName=[core_node8]
   [junit4]   2> 3792901 INFO  
(recoveryExecutor-3939-thread-1-processing-n:127.0.0.1:54124__%2Fav 
x:collection1_shard1_0_replica0 s:shard1_0 c:collection1 r:core_node8) 
[n:127.0.0.1:54124__%2Fav c:collection1 s:shard1_0 r:core_node8 
x:collection1_shard1_0_replica0] o.a.s.m.SolrMetricManager Closing metric 
reporters for: solr.core.collection1.shard1_0.replica0
   [junit4]   2> 3792902 WARN  
(updateExecutor-3938-thread-2-processing-n:127.0.0.1:54124__%2Fav 
x:collection1_shard1_0_replica0 s:shard1_0 c:collection1 r:core_node8) 
[n:127.0.0.1:54124__%2Fav c:collection1 s:shard1_0 r:core_node8 
x:collection1_shard1_0_replica0] o.a.s.u.DefaultSolrCoreState Skipping recovery 
because Solr is shutdown
   [junit4]   2> 3792904 WARN  
(zkCallback-3941-thread-2-processing-n:127.0.0.1:54124__%2Fav) 
[n:127.0.0.1:54124__%2Fav    ] o.a.s.c.c.ZkStateReader ZooKeeper watch 
triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for 
/live_nodes]
   [junit4]   2> 3792905 INFO  (zkCallback-3917-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
   [junit4]   2> 3792905 INFO  
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
   [junit4]   2> 3792907 INFO  
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@69647257{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 3792907 INFO  
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[98AF0DB26789CB34]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@ad96688{/_/av,null,UNAVAILABLE}
   [junit4]   2> 3792911 INFO  
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ChaosMonkey monkey: stop shard! 54060
   [junit4]   2> 3792912 INFO  
(TEST-ShardSplitTest.testSplitAfterFailedSplit-seed#[98AF0DB26789CB34]) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:54050 54050
   [junit4]   2> 3792935 INFO  (Thread-3905) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:54050 54050
   [junit4]   2> 3801118 WARN  (Thread-3905) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        6       /solr/aliases.json
   [junit4]   2>        6       /solr/clusterprops.json
   [junit4]   2>        5       /solr/security.json
   [junit4]   2>        5       /solr/configs/conf1
   [junit4]   2>        4       /solr/collections/collection1/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        6       /solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        82      /solr/overseer/queue
   [junit4]   2>        20      /solr/overseer/collection-queue-work
   [junit4]   2>        7       /solr/overseer/queue-work
   [junit4]   2>        6       /solr/live_nodes
   [junit4]   2>        6       /solr/collections
   [junit4]   2> 
   [junit4]   2> 3801121 INFO  
(SUITE-ShardSplitTest-seed#[98AF0DB26789CB34]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/Users/jenkins/workspace/Lucene-Solr-6.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.ShardSplitTest_98AF0DB26789CB34-001
   [junit4]   2> NOTE: test params are: codec=CheapBastard, 
sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=es-BO, 
timezone=Asia/Anadyr
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_121 
(64-bit)/cpus=3,threads=1,free=86660968,total=498675712
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolrQueryResponse, 
PreAnalyzedUpdateProcessorTest, RequestHandlersTest, PreAnalyzedFieldTest, 
TestSchemaNameResource, TestValueSourceCache, AliasIntegrationTest, 
LoggingHandlerTest, CopyFieldTest, TestCloudRecovery, ForceLeaderTest, 
ReplicaListTransformerTest, TestReplicaProperties, TestSearchPerf, 
CollectionTooManyReplicasTest, DistributedExpandComponentTest, 
TestSubQueryTransformer, TermVectorComponentTest, 
TestStressCloudBlindAtomicUpdates, OutOfBoxZkACLAndCredentialsProvidersTest, 
TestFileDictionaryLookup, SSLMigrationTest, ZkStateReaderTest, 
HighlighterConfigTest, TestSolrCoreProperties, TestXmlQParserPlugin, 
TestSlowCompositeReaderWrapper, TestCloudDeleteByQuery, TestLegacyFieldCache, 
BigEndianAscendingWordSerializerTest, DistribJoinFromCollectionTest, 
SuggesterTSTTest, TestFieldCacheReopen, TestReversedWildcardFilterFactory, 
TestLRUStatsCache, TestSystemIdResolver, BadIndexSchemaTest, TestConfig, 
IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestSolrDeletionPolicy2, 
BasicFunctionalityTest, TestCollapseQParserPlugin, TestQueryUtils, 
HdfsRecoverLeaseTest, TestAnalyzeInfixSuggestions, TestConfigSetImmutable, 
ExternalFileFieldSortTest, TestReload, TestCloudSchemaless, 
TestNonDefinedSimilarityFactory, TestStandardQParsers, UUIDFieldTest, 
TestInitParams, SortSpecParsingTest, TestJsonFacets, 
FieldMutatingUpdateProcessorTest, ReplaceNodeTest, MergeStrategyTest, 
TestCoreAdminApis, TestBulkSchemaAPI, JvmMetricsTest, TestFiltering, 
SolrMetricsIntegrationTest, TestSolrQueryParserResource, ConnectionReuseTest, 
TemplateUpdateProcessorTest, CloneFieldUpdateProcessorFactoryTest, 
HdfsUnloadDistributedZkTest, ReturnFieldsTest, DocValuesMissingTest, 
MultiThreadedOCPTest, TestObjectReleaseTracker, 
DistributedFacetPivotWhiteBoxTest, TestSystemCollAutoCreate, 
HdfsThreadLeakTest, AutoCommitTest, TestLMDirichletSimilarityFactory, 
RecoveryAfterSoftCommitTest, TestDelegationWithHadoopAuth, 
SharedFSAutoReplicaFailoverUtilsTest, BadCopyFieldTest, TestBlobHandler, 
TestSimpleTrackingShardHandler, RegexBoostProcessorTest, 
TestAuthorizationFramework, AsyncCallRequestStatusResponseTest, 
SmileWriterTest, BJQParserTest, TestCopyFieldCollectionResource, 
SolrGraphiteReporterTest, TestRealTimeGet, ShardRoutingCustomTest, 
CoreAdminHandlerTest, TestIndexingPerformance, TestExpandComponent, 
TestReloadAndDeleteDocs, PeerSyncWithIndexFingerprintCachingTest, 
SuggesterWFSTTest, TestDynamicFieldCollectionResource, 
HdfsBasicDistributedZk2Test, TestCodecSupport, SolrCmdDistributorTest, 
TermVectorComponentDistributedTest, TestLeaderInitiatedRecoveryThread, 
DeleteNodeTest, HdfsChaosMonkeyNothingIsSafeTest, DebugComponentTest, 
TestHighFrequencyDictionaryFactory, TestScoreJoinQPScore, TestSolrXml, 
TestQuerySenderListener, ManagedSchemaRoundRobinCloudTest, 
AnalyticsMergeStrategyTest, TestOmitPositions, SolrXmlInZkTest, 
LeaderFailureAfterFreshStartTest, SolrCLIZkUtilsTest, TestSQLHandler, 
DistributedQueryComponentOptimizationTest, SpellCheckCollatorTest, 
SolrSlf4jReporterTest, TestSmileRequest, MissingSegmentRecoveryTest, 
TestComplexPhraseQParserPlugin, TestSearcherReuse, LukeRequestHandlerTest, 
DistanceFunctionTest, NoCacheHeaderTest, TestIntervalFaceting, CursorMarkTest, 
TestSolr4Spatial, CollectionsAPISolrJTest, DistributedTermsComponentTest, 
DistributedVersionInfoTest, TestFieldCacheVsDocValues, SparseHLLTest, 
SolrCoreCheckLockOnStartupTest, UpdateParamsTest, SolrIndexSplitterTest, 
SearchHandlerTest, TestCustomStream, TestUseDocValuesAsStored, 
TestSizeLimitedDistributedMap, TestFieldTypeCollectionResource, 
TestExactSharedStatsCache, GraphQueryTest, AtomicUpdatesTest, JsonLoaderTest, 
TestCloudManagedSchema, TestEmbeddedSolrServerSchemaAPI, 
TestFieldCollectionResource, TestSolrCLIRunExample, 
BinaryUpdateRequestHandlerTest, WordBreakSolrSpellCheckerTest, 
TestSolrCloudWithKerberosAlt, TestSegmentSorting, 
CurrencyFieldOpenExchangeTest, TestConfigSetsAPIExclusivity, 
DistributedFacetPivotLargeTest, TestTrackingShardHandlerFactory, 
BlockDirectoryTest, TestPerFieldSimilarityWithDefaultOverride, 
DistributedIntervalFacetingTest, ResponseHeaderTest, CheckHdfsIndexTest, 
TestClassicSimilarityFactory, RAMDirectoryFactoryTest, CircularListTest, 
ChaosMonkeySafeLeaderTest, TestDocSet, OverseerTaskQueueTest, 
BasicDistributedZkTest, CollectionsAPIDistributedZkTest, RecoveryZkTest, 
TestRandomFaceting, ZkSolrClientTest, TestRecovery, TestStressVersions, 
HardAutoCommitTest, StatsComponentTest, TestGroupingSearch, 
QueryElevationComponentTest, TestBadConfig, SoftAutoCommitTest, SuggesterTest, 
TestStressLucene, TestTrie, SpatialFilterTest, TestUpdate, 
TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, 
SortByFunctionTest, TestRemoteStreaming, XsltUpdateRequestHandlerTest, 
TestSurroundQueryParser, StandardRequestHandlerTest, 
DocumentAnalysisRequestHandlerTest, TestQueryTypes, 
XmlUpdateRequestHandlerTest, MoreLikeThisHandlerTest, 
FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, IndexSchemaTest, 
TestCSVResponseWriter, QueryParsingTest, CSVRequestHandlerTest, 
TestBinaryResponseWriter, AlternateDirectoryTest, TestQuerySenderNoQuery, 
BadComponentTest, TestStressRecovery, TestTolerantSearch, AssignTest, 
BaseCdcrDistributedZkTest, CdcrBootstrapTest, ConfigSetsAPITest, 
CreateCollectionCleanupTest, DeleteInactiveReplicaTest, DeleteReplicaTest, 
DistribCursorPagingTest, LeaderElectionContextKeyTest, 
LeaderFailoverAfterPartitionTest, LeaderInitiatedRecoveryOnShardRestartTest, 
OverriddenZkACLAndCredentialsProvidersTest, ShardSplitTest]
   [junit4] Completed [538/703 (1!)] on J1 in 735.19s, 5 tests, 1 failure <<< 
FAILURES!

[...truncated 43991 lines...]

---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to