You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/07/31 16:59:51 UTC

[JENKINS] Lucene-Solr-BadApples-Tests-7.x - Build # 117 - Still Unstable

Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-7.x/117/

6 tests failed.
FAILED:  org.apache.solr.cloud.api.collections.TestHdfsCloudBackupRestore.test

Error Message:
expected:<COMPLETED> but was:<FAILED>

Stack Trace:
java.lang.AssertionError: expected:<COMPLETED> but was:<FAILED>
	at __randomizedtesting.SeedInfo.seed([D8558741996EE2C5:5001B89B37928F3D]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:147)
	at org.apache.solr.cloud.api.collections.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:325)
	at org.apache.solr.cloud.api.collections.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:146)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.api.collections.TestLocalFSCloudBackupRestore.test

Error Message:
expected:<COMPLETED> but was:<FAILED>

Stack Trace:
java.lang.AssertionError: expected:<COMPLETED> but was:<FAILED>
	at __randomizedtesting.SeedInfo.seed([D8558741996EE2C5:5001B89B37928F3D]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:147)
	at org.apache.solr.cloud.api.collections.AbstractCloudBackupRestoreTestCase.testBackupAndRestore(AbstractCloudBackupRestoreTestCase.java:325)
	at org.apache.solr.cloud.api.collections.AbstractCloudBackupRestoreTestCase.test(AbstractCloudBackupRestoreTestCase.java:146)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.update.MaxSizeAutoCommitTest.deleteTest

Error Message:
Tlog size exceeds the max size bound. Tlog path: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.update.MaxSizeAutoCommitTest_D8558741996EE2C5-001/init-core-data-001/tlog/tlog.0000000000000000002, tlog size: 1276

Stack Trace:
java.lang.AssertionError: Tlog size exceeds the max size bound. Tlog path: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J2/temp/solr.update.MaxSizeAutoCommitTest_D8558741996EE2C5-001/init-core-data-001/tlog/tlog.0000000000000000002, tlog size: 1276
	at __randomizedtesting.SeedInfo.seed([D8558741996EE2C5:C81B62BEE2C0DB34]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.update.MaxSizeAutoCommitTest.getTlogFileSizes(MaxSizeAutoCommitTest.java:383)
	at org.apache.solr.update.MaxSizeAutoCommitTest.deleteTest(MaxSizeAutoCommitTest.java:203)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.client.solrj.io.stream.StreamExpressionTest.testSignificantTermsStream

Error Message:
java.lang.NullPointerException

Stack Trace:
java.io.IOException: java.lang.NullPointerException
	at __randomizedtesting.SeedInfo.seed([7C66765A119651D0:DEA9B4C62142C3FB]:0)
	at org.apache.solr.client.solrj.io.stream.SignificantTermsStream.read(SignificantTermsStream.java:341)
	at org.apache.solr.client.solrj.io.stream.StreamExpressionTest.getTuples(StreamExpressionTest.java:2471)
	at org.apache.solr.client.solrj.io.stream.StreamExpressionTest.testSignificantTermsStream(StreamExpressionTest.java:2301)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at org.apache.solr.client.solrj.io.stream.SignificantTermsStream.read(SignificantTermsStream.java:294)
	... 41 more


FAILED:  org.apache.solr.cloud.api.collections.ShardSplitTest.test

Error Message:
Wrong doc count on shard1_1. See SOLR-5309 expected:<76> but was:<79>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_1. See SOLR-5309 expected:<76> but was:<79>
	at __randomizedtesting.SeedInfo.seed([D8558741996EE2C5:5001B89B37928F3D]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.cloud.api.collections.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:969)
	at org.apache.solr.cloud.api.collections.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:751)
	at org.apache.solr.cloud.api.collections.ShardSplitTest.test(ShardSplitTest.java:105)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1008)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:983)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.api.collections.ShardSplitTest.testSplitWithChaosMonkey

Error Message:
We think that split was successful but sub-shard states were not updated even after 2 minutes.

Stack Trace:
java.lang.AssertionError: We think that split was successful but sub-shard states were not updated even after 2 minutes.
	at __randomizedtesting.SeedInfo.seed([D8558741996EE2C5:53725490D8684941]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.api.collections.ShardSplitTest.testSplitWithChaosMonkey(ShardSplitTest.java:555)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1008)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:983)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 12383 lines...]
   [junit4] Suite: org.apache.solr.cloud.api.collections.TestLocalFSCloudBackupRestore
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/init-core-data-001
   [junit4]   2> 244495 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 244497 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 244498 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 244498 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001
   [junit4]   2> 244498 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 244506 INFO  (Thread-767) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 244506 INFO  (Thread-767) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 244507 ERROR (Thread-767) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 244606 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:34051
   [junit4]   2> 244609 INFO  (zkConnectionManagerCallback-691-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244614 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 244618 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 244619 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 244619 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 244619 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 244619 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@53d0c33f{/solr,null,AVAILABLE}
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@33a59ab{SSL,[ssl, http/1.1]}{127.0.0.1:45213}
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.e.j.s.Server Started @244684ms
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45213}
   [junit4]   2> 244628 ERROR (jetty-launcher-688-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.5.0
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244628 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-07-31T15:41:44.479Z
   [junit4]   2> 244640 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2f89d72c{/solr,null,AVAILABLE}
   [junit4]   2> 244642 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@581db64d{SSL,[ssl, http/1.1]}{127.0.0.1:37553}
   [junit4]   2> 244642 INFO  (jetty-launcher-688-thread-1) [    ] o.e.j.s.Server Started @244698ms
   [junit4]   2> 244642 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37553}
   [junit4]   2> 244643 ERROR (jetty-launcher-688-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 244643 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 244643 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 7.5.0
   [junit4]   2> 244643 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 244643 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 244643 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-07-31T15:41:44.494Z
   [junit4]   2> 244648 INFO  (zkConnectionManagerCallback-695-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244648 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244657 INFO  (zkConnectionManagerCallback-693-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244657 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 244726 INFO  (jetty-launcher-688-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34051/solr
   [junit4]   2> 244728 INFO  (zkConnectionManagerCallback-699-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244731 INFO  (zkConnectionManagerCallback-701-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244836 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:37553_solr
   [junit4]   2> 244837 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.c.Overseer Overseer (id=72079907085287428-127.0.0.1:37553_solr-n_0000000000) starting
   [junit4]   2> 244846 INFO  (zkConnectionManagerCallback-708-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 244848 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34051/solr ready
   [junit4]   2> 244848 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:37553_solr
   [junit4]   2> 244849 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37553_solr
   [junit4]   2> 244851 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 244856 INFO  (zkCallback-707-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 244871 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 244900 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 244909 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 244909 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 244911 INFO  (jetty-launcher-688-thread-1) [n:127.0.0.1:37553_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/.
   [junit4]   2> 245096 INFO  (jetty-launcher-688-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34051/solr
   [junit4]   2> 245097 INFO  (zkConnectionManagerCallback-713-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 245100 INFO  (zkConnectionManagerCallback-715-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 245109 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 245114 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245114 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45213_solr
   [junit4]   2> 245117 INFO  (zkCallback-700-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 245117 INFO  (zkCallback-707-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 245118 INFO  (zkCallback-714-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 245136 INFO  (zkConnectionManagerCallback-722-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 245137 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 245138 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34051/solr ready
   [junit4]   2> 245139 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 245158 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 245165 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 245165 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 245166 INFO  (jetty-launcher-688-thread-2) [n:127.0.0.1:45213_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/.
   [junit4]   2> 245192 INFO  (zkConnectionManagerCallback-725-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 245197 INFO  (zkConnectionManagerCallback-730-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 245199 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 245200 INFO  (SUITE-TestLocalFSCloudBackupRestore-seed#[D8558741996EE2C5]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34051/solr ready
   [junit4]   2> 245231 INFO  (TEST-TestLocalFSCloudBackupRestore.test-seed#[D8558741996EE2C5]) [    ] o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 245251 INFO  (qtp1352074681-2847) [n:127.0.0.1:37553_solr    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&router.name=implicit&version=2&pullReplicas=0&shards=shard1,shard2&property.customKey=customValue&maxShardsPerNode=-1&router.field=shard_s&autoAddReplicas=true&name=backuprestore&nrtReplicas=2&action=CREATE&tlogReplicas=1&wt=javabin and sendToOCPQueue=true
   [junit4]   2> 245254 INFO  (OverseerThreadFactory-1290-thread-1) [    ] o.a.s.c.a.c.CreateCollectionCmd Create collection backuprestore
   [junit4]   2> 245360 WARN  (OverseerThreadFactory-1290-thread-1) [    ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection backuprestore is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 245365 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37553/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245367 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:45213/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245370 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"backuprestore_shard1_replica_t4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37553/solr",
   [junit4]   2>   "type":"TLOG",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245375 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_n7",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:45213/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245377 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_n8",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:37553/solr",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245390 INFO  (OverseerStateUpdate-72079907085287428-127.0.0.1:37553_solr-n_0000000000) [    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"backuprestore",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"backuprestore_shard2_replica_t11",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:45213/solr",
   [junit4]   2>   "type":"TLOG",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 245609 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr    x:backuprestore_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 245609 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr    x:backuprestore_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 245610 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr    x:backuprestore_shard1_replica_t4] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node6&name=backuprestore_shard1_replica_t4&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 245635 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr    x:backuprestore_shard2_replica_n8] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node10&name=backuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 245650 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr    x:backuprestore_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node5&name=backuprestore_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin
   [junit4]   2> 245651 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr    x:backuprestore_shard2_replica_n7] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node9&name=backuprestore_shard2_replica_n7&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 245652 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr    x:backuprestore_shard2_replica_t11] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node12&name=backuprestore_shard2_replica_t11&action=CREATE&numShards=2&shard=shard2&wt=javabin
   [junit4]   2> 246636 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246646 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246652 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.s.IndexSchema [backuprestore_shard1_replica_t4] Schema name=minimal
   [junit4]   2> 246654 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n1] Schema name=minimal
   [junit4]   2> 246657 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246658 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n1' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246659 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.core.backuprestore.shard1.replica_n1' (registry 'solr.core.backuprestore.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246659 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246659 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/backuprestore_shard1_replica_n1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/./backuprestore_shard1_replica_n1/data/]
   [junit4]   2> 246661 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246669 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246669 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_t4' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246669 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.core.backuprestore.shard1.replica_t4' (registry 'solr.core.backuprestore.shard1.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246670 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246670 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore [[backuprestore_shard1_replica_t4] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/backuprestore_shard1_replica_t4], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/./backuprestore_shard1_replica_t4/data/]
   [junit4]   2> 246693 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246699 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246701 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.5.0
   [junit4]   2> 246706 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n8] Schema name=minimal
   [junit4]   2> 246707 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.IndexSchema [backuprestore_shard1_replica_n2] Schema name=minimal
   [junit4]   2> 246709 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246709 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246709 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard1_replica_n2' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246709 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n8' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246710 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.core.backuprestore.shard1.replica_n2' (registry 'solr.core.backuprestore.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246710 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37553.solr.core.backuprestore.shard2.replica_n8' (registry 'solr.core.backuprestore.shard2.replica_n8') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246710 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246710 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore [[backuprestore_shard1_replica_n2] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/backuprestore_shard1_replica_n2], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/./backuprestore_shard1_replica_n2/data/]
   [junit4]   2> 246710 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246710 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n8] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/backuprestore_shard2_replica_n8], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node1/./backuprestore_shard2_replica_n8/data/]
   [junit4]   2> 246715 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.s.IndexSchema [backuprestore_shard2_replica_n7] Schema name=minimal
   [junit4]   2> 246719 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246719 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_n7' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246720 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.core.backuprestore.shard2.replica_n7' (registry 'solr.core.backuprestore.shard2.replica_n7') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246720 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246720 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.SolrCore [[backuprestore_shard2_replica_n7] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/backuprestore_shard2_replica_n7], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/./backuprestore_shard2_replica_n7/data/]
   [junit4]   2> 246725 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.s.IndexSchema [backuprestore_shard2_replica_t11] Schema name=minimal
   [junit4]   2> 246728 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 246728 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.CoreContainer Creating SolrCore 'backuprestore_shard2_replica_t11' using configuration from collection backuprestore, trusted=true
   [junit4]   2> 246728 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45213.solr.core.backuprestore.shard2.replica_t11' (registry 'solr.core.backuprestore.shard2.replica_t11') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a2fd34b
   [junit4]   2> 246729 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 246729 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.SolrCore [[backuprestore_shard2_replica_t11] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/backuprestore_shard2_replica_t11], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J0/temp/solr.cloud.api.collections.TestLocalFSCloudBackupRestore_D8558741996EE2C5-001/tempDir-001/node2/./backuprestore_shard2_replica_t11/data/]
   [junit4]   2> 246825 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246825 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246826 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246826 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246828 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.s.SolrIndexSearcher Opening [Searcher@29fdfca0[backuprestore_shard1_replica_t4] main]
   [junit4]   2> 246830 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246830 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246831 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246831 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246833 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3929dabe[backuprestore_shard1_replica_n1] main]
   [junit4]   2> 246834 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246835 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246836 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246836 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226391027712
   [junit4]   2> 246836 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246836 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246837 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246837 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226392076288
   [junit4]   2> 246844 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard1 to Terms{values={core_node3=0}, version=0}
   [junit4]   2> 246871 INFO  (searcherExecutor-1303-thread-1-processing-n:127.0.0.1:37553_solr x:backuprestore_shard1_replica_t4 c:backuprestore s:shard1 r:core_node6) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.SolrCore [backuprestore_shard1_replica_t4] Registered new searcher Searcher@29fdfca0[backuprestore_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246872 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard1 to Terms{values={core_node6=0, core_node3=0}, version=1}
   [junit4]   2> 246880 INFO  (searcherExecutor-1302-thread-1-processing-n:127.0.0.1:37553_solr x:backuprestore_shard1_replica_n1 c:backuprestore s:shard1 r:core_node3) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SolrCore [backuprestore_shard1_replica_n1] Registered new searcher Searcher@3929dabe[backuprestore_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246881 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=3 found=1 timeoutin=9991ms
   [junit4]   2> 246911 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246912 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246914 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246915 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246921 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1a9391c7[backuprestore_shard1_replica_n2] main]
   [junit4]   2> 246922 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246923 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246923 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246924 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226483302400
   [junit4]   2> 246927 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246927 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246933 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246933 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246933 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246933 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246934 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246934 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246936 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.s.SolrIndexSearcher Opening [Searcher@10628349[backuprestore_shard2_replica_n8] main]
   [junit4]   2> 246937 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246938 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246939 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246939 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226499031040
   [junit4]   2> 246939 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.s.SolrIndexSearcher Opening [Searcher@22813eba[backuprestore_shard2_replica_t11] main]
   [junit4]   2> 246941 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246941 INFO  (searcherExecutor-1304-thread-1-processing-n:127.0.0.1:45213_solr x:backuprestore_shard1_replica_n2 c:backuprestore s:shard1 r:core_node5) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.SolrCore [backuprestore_shard1_replica_n2] Registered new searcher Searcher@1a9391c7[backuprestore_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246942 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246942 INFO  (searcherExecutor-1305-thread-1-processing-n:127.0.0.1:37553_solr x:backuprestore_shard2_replica_n8 c:backuprestore s:shard2 r:core_node10) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SolrCore [backuprestore_shard2_replica_n8] Registered new searcher Searcher@10628349[backuprestore_shard2_replica_n8] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246943 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246947 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 246947 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 246947 INFO  (searcherExecutor-1307-thread-1-processing-n:127.0.0.1:45213_solr x:backuprestore_shard2_replica_t11 c:backuprestore s:shard2 r:core_node12) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.SolrCore [backuprestore_shard2_replica_t11] Registered new searcher Searcher@22813eba[backuprestore_shard2_replica_t11] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246948 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226508468224
   [junit4]   2> 246948 INFO  (qtp918533514-2841) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard1 to Terms{values={core_node6=0, core_node3=0, core_node5=0}, version=2}
   [junit4]   2> 246949 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 246950 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 246950 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard2 to Terms{values={core_node10=0}, version=0}
   [junit4]   2> 246952 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.s.SolrIndexSearcher Opening [Searcher@d501091[backuprestore_shard2_replica_n7] main]
   [junit4]   2> 246954 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 246954 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=3 found=1 timeoutin=9999ms
   [junit4]   2> 246954 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 246956 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 246957 INFO  (searcherExecutor-1306-thread-1-processing-n:127.0.0.1:45213_solr x:backuprestore_shard2_replica_n7 c:backuprestore s:shard2 r:core_node9) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.SolrCore [backuprestore_shard2_replica_n7] Registered new searcher Searcher@d501091[backuprestore_shard2_replica_n7] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 246957 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1607521226517905408
   [junit4]   2> 246959 INFO  (qtp918533514-2836) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard2 to Terms{values={core_node10=0, core_node12=0}, version=1}
   [junit4]   2> 246962 INFO  (qtp918533514-2843) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.ZkShardTerms Successful update of terms at /collections/backuprestore/terms/shard2 to Terms{values={core_node10=0, core_node12=0, core_node9=0}, version=2}
   [junit4]   2> 247383 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 247383 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 247383 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37553/solr/backuprestore_shard1_replica_n1/
   [junit4]   2> 247383 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 url=https://127.0.0.1:37553/solr START replicas=[https://127.0.0.1:45213/solr/backuprestore_shard1_replica_n2/, https://127.0.0.1:37553/solr/backuprestore_shard1_replica_t4/] nUpdates=100
   [junit4]   2> 247384 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard1_replica_n1 url=https://127.0.0.1:37553/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 247389 INFO  (qtp918533514-2844) [n:127.0.0.1:45213_solr c:backuprestore s:shard1 r:core_node5 x:backuprestore_shard1_replica_n2] o.a.s.c.S.Request [backuprestore_shard1_replica_n2]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 247390 INFO  (qtp1352074681-2849) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.S.Request [backuprestore_shard1_replica_t4]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 247391 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 247391 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 247391 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 247395 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37553/solr/backuprestore_shard1_replica_n1/ shard1
   [junit4]   2> 247455 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 247455 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 247455 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:37553/solr/backuprestore_shard2_replica_n8/
   [junit4]   2> 247455 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n8 url=https://127.0.0.1:37553/solr START replicas=[https://127.0.0.1:45213/solr/backuprestore_shard2_replica_n7/, https://127.0.0.1:45213/solr/backuprestore_shard2_replica_t11/] nUpdates=100
   [junit4]   2> 247456 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.u.PeerSync PeerSync: core=backuprestore_shard2_replica_n8 url=https://127.0.0.1:37553/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 247457 INFO  (qtp918533514-2838) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node12 x:backuprestore_shard2_replica_t11] o.a.s.c.S.Request [backuprestore_shard2_replica_t11]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 247460 INFO  (qtp918533514-2838) [n:127.0.0.1:45213_solr c:backuprestore s:shard2 r:core_node9 x:backuprestore_shard2_replica_n7] o.a.s.c.S.Request [backuprestore_shard2_replica_n7]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 247460 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 247461 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 247461 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
   [junit4]   2> 247464 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:37553/solr/backuprestore_shard2_replica_n8/ shard2
   [junit4]   2> 247576 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 247578 INFO  (qtp1352074681-2850) [n:127.0.0.1:37553_solr c:backuprestore s:shard2 r:core_node10 x:backuprestore_shard2_replica_n8] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node10&name=backuprestore_shard2_replica_n8&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=1944
   [junit4]   2> 247598 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 247601 INFO  (qtp1352074681-2834) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=NRT&property.customKey=customValue&coreNodeName=core_node3&name=backuprestore_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=1992
   [junit4]   2> 247703 INFO  (zkCallback-700-thread-3) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/backuprestore/state.json] for collection [backuprestore] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 247885 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.ZkController backuprestore_shard1_replica_t4 starting background replication from leader
   [junit4]   2> 247886 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:03
   [junit4]   2> 247890 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 3000ms
   [junit4]   2> 247891 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 247891 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:37553/solr/backuprestore_shard1_replica_n1/
   [junit4]   2> 247893 INFO  (qtp1352074681-2835) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node3 x:backuprestore_shard1_replica_n1] o.a.s.c.S.Request [backuprestore_shard1_replica_n1]  webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 247894 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 247895 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 247895 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 247895 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 247895 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
   [junit4]   2> 247895 INFO  (qtp1352074681-2848) [n:127.0.0.1:37553_solr c:backuprestore s:shard1 r:core_node6 x:backuprestore_shard1_replica_t4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=backuprestore&version=2&replicaType=TLOG&property.customKey=customValue&coreNodeName=core_node6&name=backuprestore_shard1_replica_t4&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2285
   [junit4]   2> 247896 INFO  (indexFetcher-1333-thread-1) [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@360a6efd[backuprestore_shard1_replica_t4] main]
   [junit4]   2> 247897 INFO  (searcherExecutor-1303-thread-1) [    ] o.a.s.c.SolrCore [b

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

gure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null955052794
     [copy] Copying 240 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null955052794
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null955052794

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 43ms :: artifacts dl 1ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 112 minutes 50 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$34.hasMatch(FilePath.java:2678)
	at hudson.FilePath$34.invoke(FilePath.java:2557)
	at hudson.FilePath$34.invoke(FilePath.java:2547)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1036)
		at hudson.FilePath.act(FilePath.java:1025)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1819)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1038)
	at hudson.FilePath.act(FilePath.java:1025)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1819)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)

[JENKINS] Lucene-Solr-BadApples-Tests-7.x - Build # 118 - Still Unstable

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-BadApples-Tests-7.x/118/

3 tests failed.
FAILED:  org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration

Error Message:
last state: DocCollection(testSplitIntegration_collection//clusterstate.json/40)={   "replicationFactor":"1",   "pullReplicas":"0",   "router":{"name":"compositeId"},   "maxShardsPerNode":"2",   "autoAddReplicas":"false",   "nrtReplicas":"2",   "tlogReplicas":"0",   "autoCreated":"true",   "shards":{     "shard2":{       "replicas":{         "core_node3":{           "core":"testSplitIntegration_collection_shard2_replica_n3",           "leader":"true",           "SEARCHER.searcher.maxDoc":11,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":15740,           "node_name":"127.0.0.1:10006_solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.4659017324447632E-5,           "SEARCHER.searcher.numDocs":11},         "core_node4":{           "core":"testSplitIntegration_collection_shard2_replica_n4",           "SEARCHER.searcher.maxDoc":11,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":15740,           "node_name":"127.0.0.1:10007_solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.4659017324447632E-5,           "SEARCHER.searcher.numDocs":11}},       "range":"0-7fffffff",       "state":"active"},     "shard1":{       "stateTimestamp":"1533162607690832650",       "replicas":{         "core_node1":{           "core":"testSplitIntegration_collection_shard1_replica_n1",           "leader":"true",           "SEARCHER.searcher.maxDoc":14,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":17240,           "node_name":"127.0.0.1:10006_solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.605600118637085E-5,           "SEARCHER.searcher.numDocs":14},         "core_node2":{           "core":"testSplitIntegration_collection_shard1_replica_n2",           "SEARCHER.searcher.maxDoc":14,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":17240,           "node_name":"127.0.0.1:10007_solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.605600118637085E-5,           "SEARCHER.searcher.numDocs":14}},       "range":"80000000-ffffffff",       "state":"inactive"},     "shard1_1":{       "parent":"shard1",       "stateTimestamp":"1533162607691642750",       "range":"c0000000-ffffffff",       "state":"active",       "replicas":{         "core_node10":{           "leader":"true",           "core":"testSplitIntegration_collection_shard1_1_replica1",           "SEARCHER.searcher.maxDoc":7,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":13740,           "node_name":"127.0.0.1:10007_solr",           "base_url":"http://127.0.0.1:10007/solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.2796372175216675E-5,           "SEARCHER.searcher.numDocs":7},         "core_node9":{           "core":"testSplitIntegration_collection_shard1_1_replica0",           "SEARCHER.searcher.maxDoc":7,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":13740,           "node_name":"127.0.0.1:10006_solr",           "base_url":"http://127.0.0.1:10006/solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":1.2796372175216675E-5,           "SEARCHER.searcher.numDocs":7}}},     "shard1_0":{       "parent":"shard1",       "stateTimestamp":"1533162607691485750",       "range":"80000000-bfffffff",       "state":"active",       "replicas":{         "core_node7":{           "leader":"true",           "core":"testSplitIntegration_collection_shard1_0_replica0",           "SEARCHER.searcher.maxDoc":7,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":23980,           "node_name":"127.0.0.1:10006_solr",           "base_url":"http://127.0.0.1:10006/solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":2.2333115339279175E-5,           "SEARCHER.searcher.numDocs":7},         "core_node8":{           "core":"testSplitIntegration_collection_shard1_0_replica1",           "SEARCHER.searcher.maxDoc":7,           "SEARCHER.searcher.deletedDocs":0,           "INDEX.sizeInBytes":23980,           "node_name":"127.0.0.1:10007_solr",           "base_url":"http://127.0.0.1:10007/solr",           "state":"active",           "type":"NRT",           "INDEX.sizeInGB":2.2333115339279175E-5,           "SEARCHER.searcher.numDocs":7}}}}}

Stack Trace:
java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/40)={
  "replicationFactor":"1",
  "pullReplicas":"0",
  "router":{"name":"compositeId"},
  "maxShardsPerNode":"2",
  "autoAddReplicas":"false",
  "nrtReplicas":"2",
  "tlogReplicas":"0",
  "autoCreated":"true",
  "shards":{
    "shard2":{
      "replicas":{
        "core_node3":{
          "core":"testSplitIntegration_collection_shard2_replica_n3",
          "leader":"true",
          "SEARCHER.searcher.maxDoc":11,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":15740,
          "node_name":"127.0.0.1:10006_solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.4659017324447632E-5,
          "SEARCHER.searcher.numDocs":11},
        "core_node4":{
          "core":"testSplitIntegration_collection_shard2_replica_n4",
          "SEARCHER.searcher.maxDoc":11,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":15740,
          "node_name":"127.0.0.1:10007_solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.4659017324447632E-5,
          "SEARCHER.searcher.numDocs":11}},
      "range":"0-7fffffff",
      "state":"active"},
    "shard1":{
      "stateTimestamp":"1533162607690832650",
      "replicas":{
        "core_node1":{
          "core":"testSplitIntegration_collection_shard1_replica_n1",
          "leader":"true",
          "SEARCHER.searcher.maxDoc":14,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":17240,
          "node_name":"127.0.0.1:10006_solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.605600118637085E-5,
          "SEARCHER.searcher.numDocs":14},
        "core_node2":{
          "core":"testSplitIntegration_collection_shard1_replica_n2",
          "SEARCHER.searcher.maxDoc":14,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":17240,
          "node_name":"127.0.0.1:10007_solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.605600118637085E-5,
          "SEARCHER.searcher.numDocs":14}},
      "range":"80000000-ffffffff",
      "state":"inactive"},
    "shard1_1":{
      "parent":"shard1",
      "stateTimestamp":"1533162607691642750",
      "range":"c0000000-ffffffff",
      "state":"active",
      "replicas":{
        "core_node10":{
          "leader":"true",
          "core":"testSplitIntegration_collection_shard1_1_replica1",
          "SEARCHER.searcher.maxDoc":7,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":13740,
          "node_name":"127.0.0.1:10007_solr",
          "base_url":"http://127.0.0.1:10007/solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.2796372175216675E-5,
          "SEARCHER.searcher.numDocs":7},
        "core_node9":{
          "core":"testSplitIntegration_collection_shard1_1_replica0",
          "SEARCHER.searcher.maxDoc":7,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":13740,
          "node_name":"127.0.0.1:10006_solr",
          "base_url":"http://127.0.0.1:10006/solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":1.2796372175216675E-5,
          "SEARCHER.searcher.numDocs":7}}},
    "shard1_0":{
      "parent":"shard1",
      "stateTimestamp":"1533162607691485750",
      "range":"80000000-bfffffff",
      "state":"active",
      "replicas":{
        "core_node7":{
          "leader":"true",
          "core":"testSplitIntegration_collection_shard1_0_replica0",
          "SEARCHER.searcher.maxDoc":7,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":23980,
          "node_name":"127.0.0.1:10006_solr",
          "base_url":"http://127.0.0.1:10006/solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":2.2333115339279175E-5,
          "SEARCHER.searcher.numDocs":7},
        "core_node8":{
          "core":"testSplitIntegration_collection_shard1_0_replica1",
          "SEARCHER.searcher.maxDoc":7,
          "SEARCHER.searcher.deletedDocs":0,
          "INDEX.sizeInBytes":23980,
          "node_name":"127.0.0.1:10007_solr",
          "base_url":"http://127.0.0.1:10007/solr",
          "state":"active",
          "type":"NRT",
          "INDEX.sizeInGB":2.2333115339279175E-5,
          "SEARCHER.searcher.numDocs":7}}}}}
	at __randomizedtesting.SeedInfo.seed([818879CD79F237FC:B806C08D560DFE02]:0)
	at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:302)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMixedBounds

Error Message:
number of ops expected:<2> but was:<3>

Stack Trace:
java.lang.AssertionError: number of ops expected:<2> but was:<3>
	at __randomizedtesting.SeedInfo.seed([818879CD79F237FC:8B0BC66034493CA6]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMixedBounds(IndexSizeTriggerTest.java:570)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.api.collections.ShardSplitTest.testSplitWithChaosMonkey

Error Message:
We think that split was successful but sub-shard states were not updated even after 2 minutes.

Stack Trace:
java.lang.AssertionError: We think that split was successful but sub-shard states were not updated even after 2 minutes.
	at __randomizedtesting.SeedInfo.seed([818879CD79F237FC:AAFAA1C38F49C78]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.api.collections.ShardSplitTest.testSplitWithChaosMonkey(ShardSplitTest.java:555)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1008)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:983)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 13216 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
   [junit4]   2> 984149 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_818879CD79F237FC-001/init-core-data-001
   [junit4]   2> 984150 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 984151 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 984151 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_818879CD79F237FC-001/tempDir-001
   [junit4]   2> 984151 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 984151 INFO  (Thread-1858) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 984151 INFO  (Thread-1858) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 984153 ERROR (Thread-1858) [    ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 984252 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.ZkTestServer start zk server on port:34036
   [junit4]   2> 984254 INFO  (zkConnectionManagerCallback-1936-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984256 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1001995941d0000, likely client has closed socket
   [junit4]   2> 984258 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 984258 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.Server jetty-9.4.11.v20180605; built: 2018-06-05T18:24:03.829Z; git: d5fc0523cfa96bfebfbda19606cad384d772f04c; jvm 1.8.0_172-b11
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 984259 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 984260 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@a88001d{/solr,null,AVAILABLE}
   [junit4]   2> 984260 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@43ed5e50{/solr,null,AVAILABLE}
   [junit4]   2> 984267 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.AbstractConnector Started ServerConnector@12868218{HTTP/1.1,[http/1.1]}{127.0.0.1:42545}
   [junit4]   2> 984267 INFO  (jetty-launcher-1933-thread-1) [    ] o.e.j.s.Server Started @984310ms
   [junit4]   2> 984267 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42545}
   [junit4]   2> 984267 ERROR (jetty-launcher-1933-thread-1) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 984268 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 984268 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solrâ„¢ version 7.5.0
   [junit4]   2> 984268 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 984268 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 984268 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-08-01T16:21:07.571Z
   [junit4]   2> 984269 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.AbstractConnector Started ServerConnector@40b7d2d8{HTTP/1.1,[http/1.1]}{127.0.0.1:40273}
   [junit4]   2> 984269 INFO  (jetty-launcher-1933-thread-2) [    ] o.e.j.s.Server Started @984312ms
   [junit4]   2> 984269 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40273}
   [junit4]   2> 984269 INFO  (zkConnectionManagerCallback-1938-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984269 ERROR (jetty-launcher-1933-thread-2) [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 984269 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 984269 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solrâ„¢ version 7.5.0
   [junit4]   2> 984270 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 984270 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 984270 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2018-08-01T16:21:07.573Z
   [junit4]   2> 984270 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 984275 INFO  (zkConnectionManagerCallback-1940-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984275 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 984391 INFO  (jetty-launcher-1933-thread-2) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34036/solr
   [junit4]   2> 984392 INFO  (zkConnectionManagerCallback-1944-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984395 INFO  (zkConnectionManagerCallback-1946-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984425 INFO  (jetty-launcher-1933-thread-1) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34036/solr
   [junit4]   2> 984426 INFO  (zkConnectionManagerCallback-1952-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984428 INFO  (zkConnectionManagerCallback-1954-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984439 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42545_solr
   [junit4]   2> 984440 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.c.Overseer Overseer (id=72085724263677958-127.0.0.1:42545_solr-n_0000000000) starting
   [junit4]   2> 984448 INFO  (zkConnectionManagerCallback-1961-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984451 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34036/solr ready
   [junit4]   2> 984451 INFO  (OverseerStateUpdate-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:42545_solr
   [junit4]   2> 984452 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42545_solr
   [junit4]   2> 984460 INFO  (OverseerStateUpdate-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 984468 INFO  (zkCallback-1960-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 984468 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 984469 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 984470 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 984470 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 984474 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:42545_solr]
   [junit4]   2> 984475 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 984476 DEBUG (ScheduledTrigger-4313-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
   [junit4]   2> 984476 DEBUG (OverseerAutoScalingTriggerThread-72085724263677958-127.0.0.1:42545_solr-n_0000000000) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 984487 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 984514 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42545.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984521 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 984522 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42545.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984522 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42545.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984523 INFO  (jetty-launcher-1933-thread-1) [n:127.0.0.1:42545_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_818879CD79F237FC-001/tempDir-001/node1/.
   [junit4]   2> 984526 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 984526 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40273_solr
   [junit4]   2> 984535 INFO  (zkCallback-1960-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 984535 INFO  (zkCallback-1953-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 984536 INFO  (zkCallback-1945-thread-1) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 984547 INFO  (zkConnectionManagerCallback-1967-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984548 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 984549 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34036/solr ready
   [junit4]   2> 984550 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 984563 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40273.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984570 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40273.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984570 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40273.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7493931d
   [junit4]   2> 984572 INFO  (jetty-launcher-1933-thread-2) [n:127.0.0.1:40273_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_818879CD79F237FC-001/tempDir-001/node2/.
   [junit4]   2> 984594 INFO  (zkConnectionManagerCallback-1970-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984597 INFO  (zkConnectionManagerCallback-1975-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 984599 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 984599 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34036/solr ready
   [junit4]   2> 984619 DEBUG (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10006_solr
   [junit4]   2> 984619 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
   [junit4]   2> 984619 INFO  (SUITE-IndexSizeTriggerTest-seed#[818879CD79F237FC]-worker) [    ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 984620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
   [junit4]   2> 984620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
   [junit4]   2> 984620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
   [junit4]   2> 984620 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10007_solr]
   [junit4]   2> 984621 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 984621 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
   [junit4]   2> 984621 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984642 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984662 DEBUG (ScheduledTrigger-4326-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984683 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984703 DEBUG (ScheduledTrigger-4326-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984723 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984743 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984763 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984784 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984804 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984824 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984844 INFO  (TEST-IndexSizeTriggerTest.testSplitIntegration-seed#[818879CD79F237FC]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSplitIntegration
   [junit4]   2> 984844 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984865 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984885 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984888 DEBUG (simCloudManagerPool-4325-thread-6) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard2: {"core_node3":{
   [junit4]   2>     "core":"testSplitIntegration_collection_shard2_replica_n3",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":10240,
   [junit4]   2>     "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "INDEX.sizeInGB":9.5367431640625E-6,
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard2",
   [junit4]   2>     "collection":"testSplitIntegration_collection"}}
   [junit4]   2> 984889 DEBUG (simCloudManagerPool-4325-thread-7) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard1: {"core_node1":{
   [junit4]   2>     "core":"testSplitIntegration_collection_shard1_replica_n1",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":10240,
   [junit4]   2>     "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "INDEX.sizeInGB":9.5367431640625E-6,
   [junit4]   2>     "SEARCHER.searcher.numDocs":0,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"testSplitIntegration_collection"}}
   [junit4]   2> 984905 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984925 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984930 DEBUG (simCloudManagerPool-4325-thread-8) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 984930 DEBUG (simCloudManagerPool-4325-thread-8) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 984931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 984931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 984931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 984933 DEBUG (simCloudManagerPool-4325-thread-9) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 984933 DEBUG (simCloudManagerPool-4325-thread-9) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
   [junit4]   2> 984936 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
   [junit4]   2> 984937 DEBUG (simCloudManagerPool-4325-thread-10) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 984937 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 984937 DEBUG (simCloudManagerPool-4325-thread-10) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
   [junit4]   2> 984939 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 2
   [junit4]   2> 984939 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
   [junit4]   2> 984939 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 984939 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 984945 DEBUG (ScheduledTrigger-4326-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984966 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 984986 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 985006 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 985026 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 985038 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}
   [junit4]   2> 985038 DEBUG (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger, .auto_add_replicas, .scheduled_maintenance]
   [junit4]   2> 985039 INFO  (ScheduledTrigger-4326-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451363782293885, stage=STARTED, actionName='null', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985070 DEBUG (simCloudManagerPool-4325-thread-37) [    ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
   [junit4]   2>   "replicas":{"core_node1":{
   [junit4]   2>       "core":".system_shard1_replica_n1",
   [junit4]   2>       "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>       "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>       "INDEX.sizeInBytes":10240,
   [junit4]   2>       "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "type":"NRT",
   [junit4]   2>       "INDEX.sizeInGB":9.5367431640625E-6,
   [junit4]   2>       "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active"}
   [junit4]   2> 985073 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}
   [junit4]   2> 985081 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451365847835185, stage=BEFORE_ACTION, actionName='compute_plan', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985081 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 985084 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard1
   [junit4]   2> 985085 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 451366091 sessionWrapper.createTime 451365901785835, this.sessionWrapper.createTime 451365901785835 
   [junit4]   2> 985086 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451366096274035, stage=AFTER_ACTION, actionName='compute_plan', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985086 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451366121535035, stage=BEFORE_ACTION, actionName='execute_plan', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985086 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ExecutePlanAction -- processing event: {
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard@46d49fa1], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
   [junit4]   2> 985086 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard1
   [junit4]   2> 985242 DEBUG (simCloudManagerPool-4325-thread-44) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard1_0: {"core_node7":{
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":7,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":23980,
   [junit4]   2>     "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>     "base_url":"http://127.0.0.1:10006/solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "INDEX.sizeInGB":2.2333115339279175E-5,
   [junit4]   2>     "SEARCHER.searcher.numDocs":7,
   [junit4]   2>     "core":"testSplitIntegration_collection_shard1_0_replica0",
   [junit4]   2>     "shard":"shard1_0",
   [junit4]   2>     "collection":"testSplitIntegration_collection"}}
   [junit4]   2> 985242 DEBUG (simCloudManagerPool-4325-thread-43) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard1_1: {"core_node10":{
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "SEARCHER.searcher.maxDoc":7,
   [junit4]   2>     "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>     "INDEX.sizeInBytes":13740,
   [junit4]   2>     "node_name":"127.0.0.1:10007_solr",
   [junit4]   2>     "base_url":"http://127.0.0.1:10007/solr",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "INDEX.sizeInGB":1.2796372175216675E-5,
   [junit4]   2>     "SEARCHER.searcher.numDocs":7,
   [junit4]   2>     "core":"testSplitIntegration_collection_shard1_1_replica1",
   [junit4]   2>     "shard":"shard1_1",
   [junit4]   2>     "collection":"testSplitIntegration_collection"}}
   [junit4]   2> 985243 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451373965919385, stage=AFTER_ACTION, actionName='execute_plan', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.async=index_size_trigger/19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig/0, params.waitForFinalState=true, params.collection=testSplitIntegration_collection, params.shard=shard1}], properties.BEFORE_ACTION=[compute_plan, execute_plan], properties.responses=[{status={state=completed,msg=found [index_size_trigger/19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig/0] in completed tasks},success=}], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan, execute_plan]}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985243 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451373996504335, stage=SUCCEEDED, actionName='null', event={
   [junit4]   2>   "id":"19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451360503688485,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node1\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":14,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":17240,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":14,\n    \"__bytes__\":17240,\n    \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n    \"__docs__\":14,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.605600118637085E-5,\n    \"shard\":\"shard1\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451363752255435,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard1\"}]}}"]}}, context={}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985244 DEBUG (simCloudManagerPool-4325-thread-47) [    ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
   [junit4]   2>   "replicas":{"core_node1":{
   [junit4]   2>       "core":".system_shard1_replica_n1",
   [junit4]   2>       "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>       "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>       "INDEX.sizeInBytes":10240,
   [junit4]   2>       "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "type":"NRT",
   [junit4]   2>       "INDEX.sizeInGB":9.5367431640625E-6,
   [junit4]   2>       "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active"}
   [junit4]   2> 985249 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: index_size_trigger after 100ms
   [junit4]   2> 985249 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 985251 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
   [junit4]   2> 985251 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 8897 ms for event id=19a828e7ced25T5n5ceaq8ntag3cdp3itnxaiig
   [junit4]   2> 985350 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}
   [junit4]   2> 985350 DEBUG (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger, .auto_add_replicas, .scheduled_maintenance]
   [junit4]   2> 985351 INFO  (ScheduledTrigger-4326-thread-3) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451379362483435, stage=STARTED, actionName='null', event={
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}, context={}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985350 DEBUG (ScheduledTrigger-4326-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 985353 DEBUG (simCloudManagerPool-4325-thread-48) [    ] o.a.s.c.a.s.SimClusterStateProvider -- no leader in shard1:{
   [junit4]   2>   "replicas":{"core_node1":{
   [junit4]   2>       "core":".system_shard1_replica_n1",
   [junit4]   2>       "SEARCHER.searcher.maxDoc":0,
   [junit4]   2>       "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>       "INDEX.sizeInBytes":10240,
   [junit4]   2>       "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "type":"NRT",
   [junit4]   2>       "INDEX.sizeInGB":9.5367431640625E-6,
   [junit4]   2>       "SEARCHER.searcher.numDocs":0}},
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active"}
   [junit4]   2> 985353 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}
   [junit4]   2> 985353 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451379480676585, stage=BEFORE_ACTION, actionName='compute_plan', event={
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}, context={properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985353 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
   [junit4]   2> 985354 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard2
   [junit4]   2> 985354 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 451379536 sessionWrapper.createTime 451379525493935, this.sessionWrapper.createTime 451379525493935 
   [junit4]   2> 985354 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451379538437485, stage=AFTER_ACTION, actionName='compute_plan', event={
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}], properties.BEFORE_ACTION=[compute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985355 INFO  (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=451379557037485, stage=BEFORE_ACTION, actionName='execute_plan', event={
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}}, context={properties.operations=[{class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.collection=testSplitIntegration_collection, params.shard=shard2}], properties.BEFORE_ACTION=[compute_plan, execute_plan], source=index_size_trigger, properties.AFTER_ACTION=[compute_plan]}, config={
   [junit4]   2>   "trigger":"index_size_trigger",
   [junit4]   2>   "stage":[
   [junit4]   2>     "STARTED",
   [junit4]   2>     "ABORTED",
   [junit4]   2>     "SUCCEEDED",
   [junit4]   2>     "FAILED"],
   [junit4]   2>   "afterAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"],
   [junit4]   2>   "class":"org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest$CapturingTriggerListener",
   [junit4]   2>   "beforeAction":[
   [junit4]   2>     "compute_plan",
   [junit4]   2>     "execute_plan"]}, message='null'}
   [junit4]   2> 985355 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ExecutePlanAction -- processing event: {
   [junit4]   2>   "id":"19a8308bd414dT5n5ceaq8ntag3cdp3itnxaiij",
   [junit4]   2>   "source":"index_size_trigger",
   [junit4]   2>   "eventTime":451362554724685,
   [junit4]   2>   "eventType":"INDEXSIZE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "aboveSize":{"testSplitIntegration_collection":["{\"core_node3\":{\n    \"leader\":\"true\",\n    \"SEARCHER.searcher.maxDoc\":11,\n    \"SEARCHER.searcher.deletedDocs\":0,\n    \"INDEX.sizeInBytes\":15740,\n    \"node_name\":\"127.0.0.1:10006_solr\",\n    \"type\":\"NRT\",\n    \"SEARCHER.searcher.numDocs\":11,\n    \"__bytes__\":15740,\n    \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n    \"__docs__\":11,\n    \"violationType\":\"aboveDocs\",\n    \"state\":\"active\",\n    \"INDEX.sizeInGB\":1.4659017324447632E-5,\n    \"shard\":\"shard2\",\n    \"collection\":\"testSplitIntegration_collection\"}}"]},
   [junit4]   2>     "belowSize":{},
   [junit4]   2>     "_enqueue_time_":451379352113385,
   [junit4]   2>     "requestedOps":["Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n  \"first\":\"testSplitIntegration_collection\",\n  \"second\":\"shard2\"}]}}"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard@5757faf1], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
   [junit4]   2> 985355 DEBUG (AutoscalingActionExecutor-4327-thread-1) [    ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard2
   [junit4]   2> 985449 INFO  (TEST-IndexSizeTriggerTest.testSplitIntegration-seed#[818879CD79F237FC]) [    ] o.a.s.c.a.IndexSizeTriggerTest #######################################
   [junit4]   2> ############ CLUSTER STATE ############
   [junit4]   2> #######################################
   [junit4]   2> ## Live nodes:		2
   [junit4]   2> ## Empty nodes:	0
   [junit4]   2> ## Dead nodes:		0
   [junit4]   2> ## Collections:	[testSplitIntegration_collection, .system]
   [junit4]   2> DocCollection(testSplitIntegration_collection//clusterstate.json/40)={
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"2",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"2",
   [junit4]   2>   "tlogReplicas":"0",
   [junit4]   2>   "autoCreated":"true",
   [junit4]   2>   "shards":{
   [junit4]   2>     "shard2":{
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node3":{
   [junit4]   2>           "core":"testSplitIntegration_collection_shard2_replica_n3",
   [junit4]   2>           "leader":"true",
   [junit4]   2>           "SEARCHER.searcher.maxDoc":11,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":15740,
   [junit4]   2>           "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "INDEX.sizeInGB":1.4659017324447632E-5,
   [junit4]   2>           "SEARCHER.searcher.numDocs":11},
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"testSplitIntegration_collection_shard2_replica_n4",
   [junit4]   2>           "SEARCHER.searcher.maxDoc":11,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":15740,
   [junit4]   2>           "node_name":"127.0.0.1:10007_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "INDEX.sizeInGB":1.4659017324447632E-5,
   [junit4]   2>           "SEARCHER.searcher.numDocs":11}},
   [junit4]   2>       "range":"0-7fffffff",
   [junit4]   2>       "state":"active"},
   [junit4]   2>     "shard1":{
   [junit4]   2>       "stateTimestamp":"1533162607690832650",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node1":{
   [junit4]   2>           "core":"testSplitIntegration_collection_shard1_replica_n1",
   [junit4]   2>           "leader":"true",
   [junit4]   2>           "SEARCHER.searcher.maxDoc":14,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":17240,
   [junit4]   2>           "node_name":"127.0.0.1:10006_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "INDEX.sizeInGB":1.605600118637085E-5,
   [junit4]   2>           "SEARCHER.searcher.numDocs":14},
   [junit4]   2>         "core_node2":{
   [junit4]   2>           "core":"testSplitIntegration_collection_shard1_replica_n2",
   [junit4]   2>           "SEARCHER.searcher.maxDoc":14,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":17240,
   [junit4]   2>           "node_name":"127.0.0.1:10007_solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "INDEX.sizeInGB":1.605600118637085E-5,
   [junit4]   2>           "SEARCHER.searcher.numDocs":14}},
   [junit4]   2>       "range":"80000000-ffffffff",
   [junit4]   2>       "state":"inactive"},
   [junit4]   2>     "shard1_1":{
   [junit4]   2>       "parent":"shard1",
   [junit4]   2>       "stateTimestamp":"1533162607691642750",
   [junit4]   2>       "range":"c0000000-ffffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node10":{
   [junit4]   2>           "leader":"true",
   [junit4]   2>           "core":"testSplitIntegration_collection_shard1_1_replica1",
   [junit4]   2>           "SEARCHER.searcher.maxDoc":7,
   [junit4]   2>           "SEARCHER.searcher.deletedDocs":0,
   [junit4]   2>           "INDEX.sizeInBytes":13740,
   [junit4]   2>           "node_name":"127.0.0.1:10007_solr",
   [junit4]   2>           "base_url":"http://127.0.0.1:10007/solr",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "INDEX.sizeInGB":

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

gure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.

-ivy-fail-disallowed-ivy-version:

ivy-fail:

ivy-fail:

ivy-configure:
[ivy:configure] :: loading settings :: file = /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/lucene/top-level-ivy-settings.xml

resolve:

jar-checksums:
    [mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null461312756
     [copy] Copying 240 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null461312756
   [delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-BadApples-Tests-7.x/solr/null461312756

check-working-copy:
[ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working
[ivy:cachepath] 	confs: [default]
[ivy:cachepath] 	found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public
[ivy:cachepath] 	found com.jcraft#jsch;0.1.53 in public
[ivy:cachepath] 	found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpclient;4.3.6 in public
[ivy:cachepath] 	found org.apache.httpcomponents#httpcore;4.3.3 in public
[ivy:cachepath] 	found commons-logging#commons-logging;1.1.3 in public
[ivy:cachepath] 	found commons-codec#commons-codec;1.6 in public
[ivy:cachepath] 	found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 44ms :: artifacts dl 2ms
	---------------------------------------------------------------------
	|                  |            modules            ||   artifacts   |
	|       conf       | number| search|dwnlded|evicted|| number|dwnlded|
	---------------------------------------------------------------------
	|      default     |   8   |   0   |   0   |   0   ||   8   |   0   |
	---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
[wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation
[wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
[wc-checker] Checking working copy status...

-jenkins-base:

BUILD SUCCESSFUL
Total time: 104 minutes 44 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath$34.hasMatch(FilePath.java:2678)
	at hudson.FilePath$34.invoke(FilePath.java:2557)
	at hudson.FilePath$34.invoke(FilePath.java:2547)
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2918)
Also:   hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
		at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
		at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
		at hudson.remoting.Channel.call(Channel.java:955)
		at hudson.FilePath.act(FilePath.java:1036)
		at hudson.FilePath.act(FilePath.java:1025)
		at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
		at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
		at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
		at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
		at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
		at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
		at hudson.model.Build$BuildExecution.post2(Build.java:186)
		at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
		at hudson.model.Run.execute(Run.java:1819)
		at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
		at hudson.model.ResourceController.execute(ResourceController.java:97)
		at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
	at hudson.FilePath$FileCallableWrapper.call(FilePath.java:2920)
	at hudson.remoting.UserRequest.perform(UserRequest.java:212)
	at hudson.remoting.UserRequest.perform(UserRequest.java:54)
	at hudson.remoting.Request$2.run(Request.java:369)
	at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:748)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
	at hudson.FilePath.act(FilePath.java:1038)
	at hudson.FilePath.act(FilePath.java:1025)
	at hudson.FilePath.validateAntFileMask(FilePath.java:2547)
	at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
	at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
	at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
	at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
	at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
	at hudson.model.Build$BuildExecution.post2(Build.java:186)
	at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
	at hudson.model.Run.execute(Run.java:1819)
	at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
	at hudson.model.ResourceController.execute(ResourceController.java:97)
	at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)