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/06/15 03:13:19 UTC
[JENKINS] Lucene-Solr-NightlyTests-7.4 - Build # 5 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-7.4/5/
3 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration
Error Message:
did not finish processing in time
Stack Trace:
java.lang.AssertionError: did not finish processing in time
at __randomizedtesting.SeedInfo.seed([712BB0A4B11EF4A:54ABF9BAA9007AB0]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration(IndexSizeTriggerTest.java:406)
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.metrics.rrd.SolrRrdBackendFactoryTest.testBasic
Error Message:
{} expected:<1> but was:<0>
Stack Trace:
java.lang.AssertionError: {} expected:<1> but was:<0>
at __randomizedtesting.SeedInfo.seed([712BB0A4B11EF4A:ACE8A61F94CD6964]: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.metrics.rrd.SolrRrdBackendFactoryTest.testBasic(SolrRrdBackendFactoryTest.java:90)
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.PeerSyncTest.test
Error Message:
.response[0][id][0]:2!=1
Stack Trace:
junit.framework.AssertionFailedError: .response[0][id][0]:2!=1
at __randomizedtesting.SeedInfo.seed([712BB0A4B11EF4A:8F4684D0E5ED82B2]:0)
at junit.framework.Assert.fail(Assert.java:50)
at org.apache.solr.BaseDistributedSearchTestCase.compareSolrResponses(BaseDistributedSearchTestCase.java:913)
at org.apache.solr.BaseDistributedSearchTestCase.compareResponses(BaseDistributedSearchTestCase.java:940)
at org.apache.solr.BaseDistributedSearchTestCase.queryAndCompare(BaseDistributedSearchTestCase.java:650)
at org.apache.solr.BaseDistributedSearchTestCase.queryAndCompare(BaseDistributedSearchTestCase.java:641)
at org.apache.solr.update.PeerSyncTest.test(PeerSyncTest.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:993)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
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 13328 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_712BB0A4B11EF4A-001/init-core-data-001
[junit4] 2> 626349 WARN (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2
[junit4] 2> 626349 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 626351 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 626351 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 626352 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_712BB0A4B11EF4A-001/tempDir-001
[junit4] 2> 626352 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 626363 INFO (Thread-595) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 626363 INFO (Thread-595) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 626372 ERROR (Thread-595) [ ] 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> 626463 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:54125
[junit4] 2> 626512 INFO (zkConnectionManagerCallback-1545-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 626520 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 626521 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 626521 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 626521 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 626522 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 626522 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2f53ab05{/solr,null,AVAILABLE}
[junit4] 2> 626524 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@21e3298f{SSL,[ssl, http/1.1]}{127.0.0.1:41777}
[junit4] 2> 626524 INFO (jetty-launcher-1542-thread-2) [ ] o.e.j.s.Server Started @626742ms
[junit4] 2> 626524 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41777}
[junit4] 2> 626524 ERROR (jetty-launcher-1542-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 626524 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 626525 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 626525 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 626525 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 626525 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-15T01:10:34.339Z
[junit4] 2> 626527 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 626527 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 626527 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 626528 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@78e2f9a1{/solr,null,AVAILABLE}
[junit4] 2> 626528 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@20e2816c{SSL,[ssl, http/1.1]}{127.0.0.1:34813}
[junit4] 2> 626528 INFO (jetty-launcher-1542-thread-1) [ ] o.e.j.s.Server Started @626746ms
[junit4] 2> 626528 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34813}
[junit4] 2> 626529 ERROR (jetty-launcher-1542-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 626529 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 626529 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 626529 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 626529 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 626529 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-15T01:10:34.343Z
[junit4] 2> 626542 INFO (zkConnectionManagerCallback-1547-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 626542 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 626561 INFO (zkConnectionManagerCallback-1549-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 626561 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 626817 INFO (jetty-launcher-1542-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54125/solr
[junit4] 2> 626829 INFO (zkConnectionManagerCallback-1553-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 626858 INFO (zkConnectionManagerCallback-1555-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 626970 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 626971 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34813_solr
[junit4] 2> 626972 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.Overseer Overseer (id=73976287002755076-127.0.0.1:34813_solr-n_0000000000) starting
[junit4] 2> 626997 INFO (jetty-launcher-1542-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54125/solr
[junit4] 2> 626998 INFO (zkConnectionManagerCallback-1562-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627000 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54125/solr ready
[junit4] 2> 627001 INFO (zkConnectionManagerCallback-1566-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627007 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34813_solr
[junit4] 2> 627013 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 627014 INFO (zkCallback-1554-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 627014 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 627015 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 627015 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 627024 INFO (zkCallback-1561-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 627057 INFO (zkConnectionManagerCallback-1568-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627066 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:34813_solr]
[junit4] 2> 627066 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 627163 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 627231 DEBUG (ScheduledTrigger-1764-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 627241 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 627245 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 627245 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41777_solr
[junit4] 2> 627251 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 627251 DEBUG (OverseerAutoScalingTriggerThread-73976287002755076-127.0.0.1:34813_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 627252 INFO (zkCallback-1561-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 627260 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34813.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627265 INFO (zkCallback-1567-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 627272 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34813.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627272 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34813.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627273 INFO (jetty-launcher-1542-thread-1) [n:127.0.0.1:34813_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_712BB0A4B11EF4A-001/tempDir-001/node1/.
[junit4] 2> 627275 INFO (zkCallback-1554-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 627322 INFO (zkConnectionManagerCallback-1576-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627323 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 627324 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54125/solr ready
[junit4] 2> 627325 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 627396 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41777.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627428 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41777.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627428 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41777.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d13e284
[junit4] 2> 627429 INFO (jetty-launcher-1542-thread-2) [n:127.0.0.1:41777_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.IndexSizeTriggerTest_712BB0A4B11EF4A-001/tempDir-001/node2/.
[junit4] 2> 627460 INFO (zkConnectionManagerCallback-1579-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627470 INFO (zkConnectionManagerCallback-1584-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 627471 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 627472 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54125/solr ready
[junit4] 2> 627633 DEBUG (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 627634 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 627634 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 627635 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 627635 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 627639 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 627645 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 627645 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 627646 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 627648 INFO (SUITE-IndexSizeTriggerTest-seed#[712BB0A4B11EF4A]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 627666 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627688 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627708 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627728 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627748 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627768 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627789 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627809 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627829 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627849 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627869 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627890 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627893 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTrigger
[junit4] 2> 627910 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627930 DEBUG (ScheduledTrigger-1777-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627950 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627970 DEBUG (ScheduledTrigger-1777-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627989 DEBUG (simCloudManagerPool-1776-thread-6) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testTrigger_collection / shard2: {"core_node3":{
[junit4] 2> "core":"testTrigger_collection_shard2_replica_n3",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testTrigger_collection"}}
[junit4] 2> 627992 DEBUG (ScheduledTrigger-1777-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 627997 DEBUG (simCloudManagerPool-1776-thread-7) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testTrigger_collection / shard1: {"core_node1":{
[junit4] 2> "core":"testTrigger_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testTrigger_collection"}}
[junit4] 2> 628012 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628033 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628053 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628073 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628094 DEBUG (ScheduledTrigger-1777-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628114 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628134 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628154 DEBUG (ScheduledTrigger-1777-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628174 DEBUG (ScheduledTrigger-1777-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628192 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[712BB0A4B11EF4A]) [ ] 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: [testTrigger_collection]
[junit4] 2> DocCollection(testTrigger_collection//clusterstate.json/29)={
[junit4] 2> "replicationFactor":"2",
[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":"testTrigger_collection_shard2_replica_n3",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":11,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":11},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testTrigger_collection_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":11,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":11}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testTrigger_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":14,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":14},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testTrigger_collection_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":14,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":14}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> ## Max replicas per node: 2
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 4
[junit4] 2> ## * testTrigger_collection 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - update 26
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 628193 DEBUG (TEST-IndexSizeTriggerTest.testTrigger-seed#[712BB0A4B11EF4A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 628193 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 628194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 628194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 628194 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 628232 DEBUG (ScheduledTrigger-1764-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 628294 INFO (TEST-IndexSizeTriggerTest.testTrigger-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTrigger
[junit4] 2> 628352 INFO (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMixedBounds
[junit4] 2> 628352 WARN (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[712BB0A4B11EF4A]) [ ] o.a.s.c.a.IndexSizeTriggerTest Requires SOLR-12208
[junit4] 2> 628353 INFO (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[712BB0A4B11EF4A]) [ ] o.a.s.c.a.IndexSizeTriggerTest #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 2
[junit4] 2> ## Empty nodes: 2
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 628353 DEBUG (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[712BB0A4B11EF4A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 628353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 628353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 628353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 628353 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 628530 INFO (TEST-IndexSizeTriggerTest.testMixedBounds-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMixedBounds
[junit4] 2> 628560 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testMergeIntegration
[junit4] 2> 628626 DEBUG (simCloudManagerPool-1776-thread-40) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testMergeIntegration_collection / shard1: {"core_node1":{
[junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testMergeIntegration_collection"}}
[junit4] 2> 628718 DEBUG (simCloudManagerPool-1776-thread-52) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 628718 DEBUG (simCloudManagerPool-1776-thread-52) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 628719 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 628719 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 628719 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 628719 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 628726 DEBUG (simCloudManagerPool-1776-thread-53) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 628726 DEBUG (simCloudManagerPool-1776-thread-53) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 628726 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 628727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 628727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 628727 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 628734 DEBUG (simCloudManagerPool-1776-thread-54) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 628734 DEBUG (simCloudManagerPool-1776-thread-54) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 628734 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 628734 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 628734 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 628734 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 629233 DEBUG (ScheduledTrigger-1764-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 630048 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[712BB0A4B11EF4A]) [ ] 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: [testMergeIntegration_collection]
[junit4] 2> DocCollection(testMergeIntegration_collection//clusterstate.json/51)={
[junit4] 2> "replicationFactor":"2",
[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":"testMergeIntegration_collection_shard2_replica_n3",
[junit4] 2> "SEARCHER.searcher.maxDoc":3,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":3},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testMergeIntegration_collection_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc":3,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":3}},
[junit4] 2> "range":"0-7fffffff",
[junit4] 2> "state":"active"},
[junit4] 2> "shard1":{
[junit4] 2> "replicas":{
[junit4] 2> "core_node1":{
[junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":7,
[junit4] 2> "SEARCHER.searcher.deletedDocs":5,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":2},
[junit4] 2> "core_node2":{
[junit4] 2> "core":"testMergeIntegration_collection_shard1_replica_n2",
[junit4] 2> "SEARCHER.searcher.maxDoc":7,
[junit4] 2> "SEARCHER.searcher.deletedDocs":5,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":2}},
[junit4] 2> "range":"80000000-ffffffff",
[junit4] 2> "state":"active"}}}
[junit4] 2> ## Max replicas per node: 2
[junit4] 2> ## Min replicas per node: 2
[junit4] 2> ## Total replicas: 4
[junit4] 2> ## * testMergeIntegration_collection 4
[junit4] 2> ## - active 4
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - CREATE 1
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 17
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> 630048 DEBUG (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[712BB0A4B11EF4A]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 630048 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 630049 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 630049 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 630049 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 630148 INFO (TEST-IndexSizeTriggerTest.testMergeIntegration-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMergeIntegration
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=IndexSizeTriggerTest -Dtests.method=testMergeIntegration -Dtests.seed=712BB0A4B11EF4A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/test-data/enwiki.random.lines.txt -Dtests.locale=tr-TR -Dtests.timezone=Asia/Tokyo -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 1.62s J1 | IndexSizeTriggerTest.testMergeIntegration <<<
[junit4] > Throwable #1: java.lang.AssertionError: did not finish processing in time
[junit4] > at __randomizedtesting.SeedInfo.seed([712BB0A4B11EF4A:54ABF9BAA9007AB0]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testMergeIntegration(IndexSizeTriggerTest.java:406)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 630227 INFO (TEST-IndexSizeTriggerTest.testSplitIntegration-seed#[712BB0A4B11EF4A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSplitIntegration
[junit4] 2> 630233 DEBUG (ScheduledTrigger-1764-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 630292 DEBUG (simCloudManagerPool-1776-thread-66) [ ] 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":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 630292 DEBUG (simCloudManagerPool-1776-thread-67) [ ] 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":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":0,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 630302 DEBUG (simCloudManagerPool-1776-thread-68) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 630302 DEBUG (simCloudManagerPool-1776-thread-68) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 630302 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 630302 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 630302 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 630302 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 630309 DEBUG (simCloudManagerPool-1776-thread-69) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 630309 DEBUG (simCloudManagerPool-1776-thread-69) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 630309 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 630310 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 630310 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 630310 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 630314 DEBUG (simCloudManagerPool-1776-thread-70) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 630315 DEBUG (simCloudManagerPool-1776-thread-70) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 630315 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 630315 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 630315 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 630315 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 630542 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard2\"}]}}"]}}
[junit4] 2> 630543 DEBUG (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [index_size_trigger]
[junit4] 2> 630545 INFO (ScheduledTrigger-1777-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277085715253168, stage=STARTED, actionName='null', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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> 630581 DEBUG (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard2\"}]}}"]}}
[junit4] 2> 630586 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277087676069268, stage=BEFORE_ACTION, actionName='compute_plan', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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> 630586 DEBUG (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard2\"}]}}"]}} with context properties: {BEFORE_ACTION=[compute_plan]}
[junit4] 2> 630590 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard1
[junit4] 2> 630590 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard2
[junit4] 2> 630590 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 29277087994 sessionWrapper.createTime 29277087848760368, this.sessionWrapper.createTime 29277087848760368
[junit4] 2> 630591 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277087996769018, stage=AFTER_ACTION, actionName='compute_plan', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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=shard1}, {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> 630591 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277088027201918, stage=BEFORE_ACTION, actionName='execute_plan', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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=shard1}, {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> 630592 DEBUG (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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@190035eb, org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard@5d696a9e], AFTER_ACTION=[compute_plan], BEFORE_ACTION=[compute_plan, execute_plan]}
[junit4] 2> 630592 DEBUG (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard1
[junit4] 2> 630758 DEBUG (simCloudManagerPool-1776-thread-103) [ ] 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":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10000/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[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> 630759 DEBUG (simCloudManagerPool-1776-thread-104) [ ] 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":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10001/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[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> 630773 DEBUG (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=SPLITSHARD&collection=testSplitIntegration_collection&shard=shard2
[junit4] 2> 631081 DEBUG (simCloudManagerPool-1776-thread-110) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard2_1: {"core_node16":{
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":5,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10000/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":5,
[junit4] 2> "core":"testSplitIntegration_collection_shard2_1_replica1",
[junit4] 2> "shard":"shard2_1",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 631097 DEBUG (simCloudManagerPool-1776-thread-113) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testSplitIntegration_collection / shard2_0: {"core_node14":{
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":6,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":1,
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "base_url":"http://127.0.0.1:10000/solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":6,
[junit4] 2> "core":"testSplitIntegration_collection_shard2_0_replica1",
[junit4] 2> "shard":"shard2_0",
[junit4] 2> "collection":"testSplitIntegration_collection"}}
[junit4] 2> 631100 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277113451388118, stage=AFTER_ACTION, actionName='execute_plan', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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.async=index_size_trigger/68035930a9e146T1ud06rhihgmklskcsd5fzn049/0, params.waitForFinalState=true, params.collection=testSplitIntegration_collection, params.shard=shard1}, {class=org.apache.solr.client.solrj.request.CollectionAdminRequest$SplitShard, method=GET, params.action=SPLITSHARD, params.async=index_size_trigger/68035930a9e146T1ud06rhihgmklskcsd5fzn049/0, params.waitForFinalState=true, params.collection=testSplitIntegration_collection, params.shard=shard2}], properties.BEFORE_ACTION=[compute_plan, execute_plan], properties.responses=[{status={state=completed,msg=found [index_size_trigger/68035930a9e146T1ud06rhihgmklskcsd5fzn049/0] in completed tasks},success=}, {status={state=completed,msg=found [index_size_trigger/68035930a9e146T1ud06rhihgmklskcsd5fzn049/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> 631101 INFO (AutoscalingActionExecutor-1778-thread-1) [ ] o.a.s.c.a.IndexSizeTriggerTest =======> CapturedEvent{timestamp=29277113504348418, stage=SUCCEEDED, actionName='null', event={
[junit4] 2> "id":"68035930a9e146T1ud06rhihgmklskcsd5fzn049",
[junit4] 2> "source":"index_size_trigger",
[junit4] 2> "eventTime":29277079181320518,
[junit4] 2> "eventType":"INDEXSIZE",
[junit4] 2> "properties":{
[junit4] 2> "__start__":2,
[junit4] 2> "aboveSize":{"testSplitIntegration_collection":[
[junit4] 2> "{\"core_node1\":{\n \"core\":\"testSplitIntegration_collection_shard1_replica_n1\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":14,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":14,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":14,\n \"__bytes__\":1,\n \"shard\":\"shard1\",\n \"collection\":\"testSplitIntegration_collection\"}}",
[junit4] 2> "{\"core_node3\":{\n \"core\":\"testSplitIntegration_collection_shard2_replica_n3\",\n \"leader\":\"true\",\n \"SEARCHER.searcher.maxDoc\":11,\n \"SEARCHER.searcher.deletedDocs\":0,\n \"INDEX.sizeInBytes\":1,\n \"__docs__\":11,\n \"violationType\":\"aboveDocs\",\n \"node_name\":\"127.0.0.1:10001_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"SEARCHER.searcher.numDocs\":11,\n \"__bytes__\":1,\n \"shard\":\"shard2\",\n \"collection\":\"testSplitIntegration_collection\"}}"]},
[junit4] 2> "belowSize":{},
[junit4] 2> "_enqueue_time_":29277085646141518,
[junit4] 2> "requestedOps":[
[junit4] 2> "Op{action=SPLITSHARD, hints={COLL_SHARD=[{\n \"first\":\"testSplitIntegration_collection\",\n \"second\":\"shard1\"}]}}",
[junit4] 2> "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> 631126 INFO (TEST-IndexSizeTriggerTest.testSplitIntegration-seed#[712BB0A4B11EF4A]) [ ] 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/95)={
[junit4] 2> "replicationFactor":"2",
[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> "stateTimestamp":"1529025214961566400",
[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":1,
[junit4] 2> "node_name":"127.0.0.1:10001_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.numDocs":11},
[junit4] 2> "core_node4":{
[junit4] 2> "core":"testSplitIntegration_collection_shard2_replica_n4",
[junit4] 2> "SEARCHER.searcher.maxDoc"
[...truncated too long message...]
/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null1824273427
[copy] Copying 39 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null1824273427
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null1824273427
resolve-example:
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-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
resolve-server:
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-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/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-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null1578747812
[copy] Copying 247 files to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null1578747812
[delete] Deleting directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null1578747812
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 73ms :: artifacts dl 7ms
---------------------------------------------------------------------
| | 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: 393 minutes 15 seconds
Archiving artifacts
WARN: No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
WARN: java.lang.InterruptedException: no matches found within 10000
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-NightlyTests-7.4 - Build # 6 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-7.4/6/
3 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration
Error Message:
last state: DocCollection(testSplitIntegration_collection//clusterstate.json/41)={ "replicationFactor":"2", "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":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}, "core_node4":{ "core":"testSplitIntegration_collection_shard2_replica_n4", "SEARCHER.searcher.maxDoc":11, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":11}}, "range":"0-7fffffff", "state":"active"}, "shard1":{ "replicas":{ "core_node1":{ "core":"testSplitIntegration_collection_shard1_replica_n1", "leader":"true", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10000_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}, "core_node2":{ "core":"testSplitIntegration_collection_shard1_replica_n2", "SEARCHER.searcher.maxDoc":14, "SEARCHER.searcher.deletedDocs":0, "INDEX.sizeInBytes":1, "node_name":"127.0.0.1:10001_solr", "state":"active", "type":"NRT", "SEARCHER.searcher.numDocs":14}}, "range":"80000000-ffffffff", "state":"active"}}}
Stack Trace:
java.util.concurrent.TimeoutException: last state: DocCollection(testSplitIntegration_collection//clusterstate.json/41)={
"replicationFactor":"2",
"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":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11},
"core_node4":{
"core":"testSplitIntegration_collection_shard2_replica_n4",
"SEARCHER.searcher.maxDoc":11,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":11}},
"range":"0-7fffffff",
"state":"active"},
"shard1":{
"replicas":{
"core_node1":{
"core":"testSplitIntegration_collection_shard1_replica_n1",
"leader":"true",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10000_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14},
"core_node2":{
"core":"testSplitIntegration_collection_shard1_replica_n2",
"SEARCHER.searcher.maxDoc":14,
"SEARCHER.searcher.deletedDocs":0,
"INDEX.sizeInBytes":1,
"node_name":"127.0.0.1:10001_solr",
"state":"active",
"type":"NRT",
"SEARCHER.searcher.numDocs":14}},
"range":"80000000-ffffffff",
"state":"active"}}}
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:5D95688B9EDC0B4D]:0)
at org.apache.solr.cloud.CloudTestUtils.waitForState(CloudTestUtils.java:111)
at org.apache.solr.cloud.autoscaling.IndexSizeTriggerTest.testSplitIntegration(IndexSizeTriggerTest.java:300)
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.SystemLogListenerTest.test
Error Message:
Trigger was not fired
Stack Trace:
java.lang.AssertionError: Trigger was not fired
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:EC4FEE111FDFAF4B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.SystemLogListenerTest.test(SystemLogListenerTest.java:151)
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.sim.TestTriggerIntegration.testTriggerThrottling
Error Message:
Both triggers should have fired by now
Stack Trace:
java.lang.AssertionError: Both triggers should have fired by now
at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:9F3979EE63892121]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testTriggerThrottling(TestTriggerIntegration.java:185)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13385 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
[junit4] 2> 123656 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_641BD1CBB123C2B3-001/init-core-data-001
[junit4] 2> 123658 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 123660 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 125925 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 125927 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 125947 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 125976 INFO (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 126024 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 126024 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 126045 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] IGNOR/A 0.07s J0 | TestTriggerIntegration.testNodeLostTriggerRestoreState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 126080 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126080 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 126081 DEBUG (ScheduledTrigger-66-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126266 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126359 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126379 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126392 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 126393 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 126394 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 126394 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 126412 DEBUG (ScheduledTrigger-66-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 126429 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 126431 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 126431 DEBUG (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 126433 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 126434 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 126469 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126489 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126490 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 126490 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126652 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126655 DEBUG (simCloudManagerPool-70-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126655 DEBUG (simCloudManagerPool-70-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 126710 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126712 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 126713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 126713 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 126746 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126764 DEBUG (simCloudManagerPool-70-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126765 DEBUG (simCloudManagerPool-70-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 126782 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 126784 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126784 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 126785 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126785 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126785 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 126912 DEBUG (ScheduledTrigger-71-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 126921 DEBUG (simCloudManagerPool-70-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 126921 DEBUG (simCloudManagerPool-70-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 126922 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126922 DEBUG (ScheduledTrigger-71-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126930 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 126931 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$ThrottlingTesterAction}], enabled=true}
[junit4] 2> 126931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 126931 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2
[junit4] 2> 126931 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
[junit4] 2> 126949 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10002_solr at time 11462030256135597
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10002_solr] added at times [11462030256135597], now=11462030259808797
[junit4] 2> 126950 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":11462030256135597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462030256135597],
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 126966 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger2, node_added_trigger1]
[junit4] 2> 127348 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 127350 INFO (TEST-TestTriggerIntegration.testTriggerThrottling-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 3
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: []
[junit4] 2> ## Max replicas per node: 0
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 0
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 1
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2>
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testTriggerThrottling -Dtests.seed=641BD1CBB123C2B3 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/test-data/enwiki.random.lines.txt -Dtests.locale=sl -Dtests.timezone=Canada/Newfoundland -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 1.39s J0 | TestTriggerIntegration.testTriggerThrottling <<<
[junit4] > Throwable #1: java.lang.AssertionError: Both triggers should have fired by now
[junit4] > at __randomizedtesting.SeedInfo.seed([641BD1CBB123C2B3:9F3979EE63892121]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testTriggerThrottling(TestTriggerIntegration.java:185)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testCooldown
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testEventFromRestoredState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.02s J0 | TestTriggerIntegration.testNodeMarkersRegistration
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 127605 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 127605 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 127606 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimNodeStateProvider --removing value for 127.0.0.1:10002_solr
[junit4] 2> 127606 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 127608 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 127657 DEBUG (ScheduledTrigger-71-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10002_solr
[junit4] 2> 127657 DEBUG (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":11462030256135597,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462030256135597],
[junit4] 2> "_enqueue_time_":11462031064994597,
[junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}}
[junit4] 2> 127658 INFO (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.s.TestTriggerIntegration action executed from node_added_trigger1
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 127677 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 127658 WARN (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions
[junit4] 2> java.lang.NullPointerException: null
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:320) ~[java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_172]
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) ~[java/:?]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 127821 DEBUG (AutoscalingActionExecutor-72-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 8214 ms for event id=28b8a7e1d25dadT8przpsfvi6vl8wmgcj3nfzu7t
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 127822 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 127856 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1
[junit4] 2> 127857 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 127892 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 127912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 127912 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 127913 DEBUG (ScheduledTrigger-74-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 127978 DEBUG (simCloudManagerPool-73-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 127978 DEBUG (simCloudManagerPool-73-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 128039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 128039 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128060 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128095 DEBUG (ScheduledTrigger-74-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 128097 DEBUG (simCloudManagerPool-73-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 128098 DEBUG (simCloudManagerPool-73-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
[junit4] 2> 128111 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9
[junit4] 2> 128112 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 128112 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128113 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 11462088427305797
[junit4] 2> 128132 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 128133 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128133 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128152 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [11462088427305797], now=11462090481367097
[junit4] 2> 128154 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":11462088427305797,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462088427305797],
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 128168 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 128234 DEBUG (ScheduledTrigger-74-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger - removing marker path: /autoscaling/nodeAdded/127.0.0.1:10003_solr
[junit4] 2> 128255 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":11462088427305797,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[11462088427305797],
[junit4] 2> "_enqueue_time_":11462091199083347,
[junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}}
[junit4] 2> 128290 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 128291 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 128291 DEBUG (AutoscalingActionExecutor-75-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1768 ms for event id=28b8b56d17fb45T8przpsfvi6vl8wmgcj3nfzu7v
[junit4] 2> 128348 DEBUG (simCloudManagerPool-73-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 128348 DEBUG (simCloudManagerPool-73-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
[junit4] 2> 128363 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
[junit4] 2> 128364 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 128400 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 128403 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[641BD1CBB123C2B3]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #######################################
[junit4] 2> ############ CLUSTER STATE ############
[junit4] 2> #######################################
[junit4] 2> ## Live nodes: 3
[junit4] 2> ## Empty nodes: 2
[junit4] 2> ## Dead nodes: 0
[junit4] 2> ## Collections: [.system]
[junit4] 2> ## Max replicas per node: 1
[junit4] 2> ## Min replicas per node: 0
[junit4] 2> ## Total replicas: 1
[junit4] 2> ## * .system 1
[junit4] 2> ## - active 1
[junit4] 2> ######### Solr op counts ##########
[junit4] 2> ## - autoscaling 3
[junit4] 2> ## - update 2
[junit4] 2> ######### Autoscaling event counts ###########
[junit4] 2> ## * Trigger: node_added_trigger
[junit4] 2> ## - STARTED 1
[junit4] 2> ## - SUCCEEDED 1
[junit4] 2>
[junit4] 2> 128403 DEBUG (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testSearchRate
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testListeners
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testNodeAddedTriggerRestoreState
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testEventQueue
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] IGNOR/A 0.00s J0 | TestTriggerIntegration.testNodeLostTrigger
[junit4] > Assumption #1: 'badapple' test group is disabled (@BadApple(bugUrl=https://issues.apache.org/jira/browse/SOLR-12028))
[junit4] 2> 128423 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 128423 WARN (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger ran but was already closed
[junit4] 2> 128424 ERROR (ScheduledTrigger-74-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Unexpected exception in NodeAddedTrigger
[junit4] 2> java.lang.RuntimeException: Trigger has been closed
[junit4] 2> at org.apache.solr.cloud.autoscaling.NodeAddedTrigger.run(NodeAddedTrigger.java:121) [java/:?]
[junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerWrapper.run(ScheduledTriggers.java:589) [java/:?]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_172]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_172]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_172]
[junit4] 2> 128436 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 128457 DEBUG (SUITE-TestTriggerIntegration-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_641BD1CBB123C2B3-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1251, maxMBSortInHeap=7.53348972723326, sim=RandomSimilarity(queryNorm=true): {}, locale=sl, timezone=Canada/Newfoundland
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_172 (64-bit)/cpus=4,threads=1,free=217110632,total=279445504
[junit4] 2> NOTE: All tests run in this JVM: [TestCollationField, RestoreTriggerStateTest, TestTriggerIntegration]
[junit4] Completed [7/817 (1!)] on J0 in 5.52s, 11 tests, 1 failure, 9 skipped <<< FAILURES!
[...truncated 37 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.SystemLogListenerTest
[junit4] 2> 128731 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/init-core-data-001
[junit4] 2> 128751 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 128753 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 128786 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001
[junit4] 2> 128787 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 128807 INFO (Thread-44) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 128807 INFO (Thread-44) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 128823 ERROR (Thread-44) [ ] 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> 128912 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35652
[junit4] 2> 129099 INFO (zkConnectionManagerCallback-81-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 129490 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129491 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129494 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.Server jetty-9.4.10.v20180503; built: 2018-05-03T15:56:21.710Z; git: daa59876e6f384329b122929e70a80934569428c; jvm 1.8.0_172-b11
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129656 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129657 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6ae364ae{/solr,null,AVAILABLE}
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5a959c13{HTTP/1.1,[http/1.1]}{127.0.0.1:40138}
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.e.j.s.Server Started @129897ms
[junit4] 2> 129682 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40138}
[junit4] 2> 129683 ERROR (jetty-launcher-78-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129683 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.054Z
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129780 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129794 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@24f564e8{/solr,null,AVAILABLE}
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5b81883a{HTTP/1.1,[http/1.1]}{127.0.0.1:35754}
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.e.j.s.Server Started @130010ms
[junit4] 2> 129795 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35754}
[junit4] 2> 129796 ERROR (jetty-launcher-78-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129796 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.167Z
[junit4] 2> 129851 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 129851 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 129852 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 129880 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@48fc3aea{/solr,null,AVAILABLE}
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7ba465c5{HTTP/1.1,[http/1.1]}{127.0.0.1:45600}
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.e.j.s.Server Started @130096ms
[junit4] 2> 129881 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45600}
[junit4] 2> 129881 ERROR (jetty-launcher-78-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.4.0
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 129882 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-06-16T04:49:28.253Z
[junit4] 2> 130071 INFO (zkConnectionManagerCallback-87-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130071 INFO (zkConnectionManagerCallback-85-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130095 INFO (zkConnectionManagerCallback-83-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 130108 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 130108 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 130109 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 132416 INFO (jetty-launcher-78-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 132629 INFO (zkConnectionManagerCallback-91-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 132764 INFO (zkConnectionManagerCallback-93-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133123 INFO (jetty-launcher-78-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 133313 INFO (zkConnectionManagerCallback-99-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133577 INFO (jetty-launcher-78-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35652/solr
[junit4] 2> 133737 INFO (zkConnectionManagerCallback-105-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 133833 INFO (zkConnectionManagerCallback-101-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 134037 INFO (zkConnectionManagerCallback-107-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 134586 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 134587 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45600_solr
[junit4] 2> 134606 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.Overseer Overseer (id=72808765580443656-127.0.0.1:45600_solr-n_0000000000) starting
[junit4] 2> 134660 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 134680 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35754_solr
[junit4] 2> 134861 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135056 INFO (zkCallback-100-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135401 INFO (zkConnectionManagerCallback-116-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 135649 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135674 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 135690 INFO (zkConnectionManagerCallback-121-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 135712 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 135712 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 135728 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 135728 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45600_solr
[junit4] 2> 135729 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 135763 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 135764 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 135765 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 135765 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 135766 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 135893 INFO (zkCallback-115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 135910 INFO (zkCallback-100-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 136021 INFO (zkCallback-120-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 136138 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 136573 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136686 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136689 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:35754_solr, 127.0.0.1:45600_solr]
[junit4] 2> 136844 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 136864 DEBUG (OverseerAutoScalingTriggerThread-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 136865 DEBUG (ScheduledTrigger-93-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 136877 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136877 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136879 INFO (jetty-launcher-78-thread-2) [n:127.0.0.1:45600_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/.
[junit4] 2> 136914 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136914 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35754.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 136935 INFO (jetty-launcher-78-thread-1) [n:127.0.0.1:35754_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node3/.
[junit4] 2> 137952 DEBUG (ScheduledTrigger-93-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 138357 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 138428 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 138560 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 138560 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40138_solr
[junit4] 2> 138723 INFO (zkCallback-106-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138743 INFO (zkCallback-120-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138743 INFO (zkCallback-100-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138760 INFO (zkCallback-115-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138856 INFO (zkCallback-92-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 138952 DEBUG (ScheduledTrigger-93-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 139004 INFO (zkConnectionManagerCallback-128-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 139080 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 139264 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 139280 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 139479 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139647 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139647 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 139649 INFO (jetty-launcher-78-thread-3) [n:127.0.0.1:40138_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/.
[junit4] 2> 140086 DEBUG (ScheduledTrigger-93-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 140500 INFO (zkConnectionManagerCallback-131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 140624 INFO (zkConnectionManagerCallback-136-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 140626 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 140640 INFO (SUITE-SystemLogListenerTest-seed#[641BD1CBB123C2B3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35652/solr ready
[junit4] 2> 140701 INFO (qtp103186778-272) [n:127.0.0.1:45600_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=3&name=.system&nrtReplicas=3&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 141094 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 141172 INFO (OverseerThreadFactory-95-thread-1) [ ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 141666 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:40138/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 141682 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:35754/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 141719 INFO (OverseerStateUpdate-72808765580443656-127.0.0.1:45600_solr-n_0000000000) [ ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45600/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 142095 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 142098 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr x:.system_shard1_replica_n3] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n3&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 142225 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr x:.system_shard1_replica_n2] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 142226 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr x:.system_shard1_replica_n2] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 142243 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr x:.system_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 143111 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 143581 WARN (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.Config You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
[junit4] 2> 143632 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 143634 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 143654 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0
[junit4] 2> 144011 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144011 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144026 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 144086 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.IndexSchema [.system_shard1_replica_n3] Schema name=_system collection or core
[junit4] 2> 144100 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 144119 DEBUG (ScheduledTrigger-93-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
[junit4] 2> 144121 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 144382 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144413 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144425 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 144500 INFO (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 144534 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 144537 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 144537 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from collection .system, trusted=true
[junit4] 2> 144538 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40138.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 144556 INFO (qtp1851139547-252) [n:127.0.0.1:40138_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 144575 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, the non-managed schema /configs/.system/schema.xml no longer exists.
[junit4] 2> 144575 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n3' using configuration from collection .system, trusted=true
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45600.solr.core..system.shard1.replica_n3' (registry 'solr.core..system.shard1.replica_n3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@21c7ed6
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 144576 INFO (qtp103186778-267) [n:127.0.0.1:45600_solr c:.system s:shard1 r:core_node6 x:.system_shard1_replica_n3] o.a.s.c.SolrCore [[.system_shard1_replica_n3] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/.system_shard1_replica_n3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.SystemLogListenerTest_641BD1CBB123C2B3-001/tempDir-001/node1/./.system_shard1_replica_n3/data/]
[junit4] 2> 144612 WARN (qtp1026513340-261) [n:127.0.0.1:35754_solr c:.system s:shard1 r:core_node5 x:.system_shard1_replica_n2] o.a.s.s.ManagedIndexSchemaFactory Error persisting managed schema resource managed-schema
[junit4] 2> org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /configs/.system/schema.xml
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:114) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:876) ~[zookeeper-3.4.11.jar:3.4.11-37e277162d567b55a07d1755f0b31c32e93c01a0]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$delete$1(SolrZkClient.java:245) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:244) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.zkUgradeToManagedSchema(ManagedIndexSchemaFactory.java:349) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.upgradeToManagedSchema(ManagedIndexSchemaFactory.java:268) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:186) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.ManagedIndexSchemaFactory.create(ManagedIndexSchemaFactory.java:45) ~[java/:?]
[junit4] 2> at org.apache.solr.schema.IndexSchemaFactory.buildIndexSchema(IndexSchemaFactory.java:75) ~[java/:?]
[junit4] 2> at org.apache.solr.core.ConfigSetService.createIndexSchema(ConfigSetService.java:119) ~[java/:?]
[junit4] 2> at org.apache.solr.core.ConfigSetService.getConfig(ConfigSetService.java:92) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.getConfigSet(CoreContainer.java:1184) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1131) ~[java/:?]
[junit4] 2> at org.apache.solr.core.CoreContainer.create(CoreContainer.java:1045) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:94) ~[java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:380) [java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:395) [java/:?]
[junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:180) [java/:?]
[junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:734) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:715) [java/:?]
[junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:496) [java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:377) [java/:?]
[junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:323) [java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139) [java/:?]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1642) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:533) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1253) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [jetty-servlet-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1155) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:674) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:531) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:352) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [jetty-server-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [jetty-io-9.4.10.v20180503.jar:9.4.10.v20180503]
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:760) [jetty-util-9.4.10.v20180503.j
[...truncated too long message...]
ability-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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
[copy] Copying 39 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/null951307880
resolve-example:
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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
resolve-server:
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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/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 = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
[copy] Copying 247 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.4/checkout/solr/null516622629
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 65ms :: artifacts dl 5ms
---------------------------------------------------------------------
| | 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: 759 minutes 10 seconds
Archiving artifacts
WARN: No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
WARN: java.lang.InterruptedException: no matches found within 10000
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)