Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1012/ Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
3 tests failed. FAILED: org.apache.solr.cloud.CleanupOldIndexTest.test Error Message: Stack Trace: java.util.concurrent.TimeoutException at __randomizedtesting.SeedInfo.seed([43CAB3C5B0A06BB3:CB9E8C1F1E5C064B]:0) at org.apache.solr.common.cloud.ZkStateReader.waitForState(ZkStateReader.java:1261) at org.apache.solr.client.solrj.impl.CloudSolrClient.waitForState(CloudSolrClient.java:449) at org.apache.solr.cloud.CleanupOldIndexTest.test(CleanupOldIndexTest.java:114) 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.CollectionsAPIDistributedZkTest.testCollectionsAPI Error Message: Error from server at http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1: ClusterState says we are the leader (http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1), but locally we don't think so. Request came from null Stack Trace: org.apache.solr.client.solrj.impl.CloudSolrClient$RouteException: Error from server at http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1: ClusterState says we are the leader (http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1), but locally we don't think so. Request came from null at __randomizedtesting.SeedInfo.seed([43CAB3C5B0A06BB3:BBFC771B6934426]:0) at org.apache.solr.client.solrj.impl.CloudSolrClient.directUpdate(CloudSolrClient.java:550) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1013) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:946) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194) at org.apache.solr.client.solrj.request.UpdateRequest.commit(UpdateRequest.java:233) at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:460) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1: ClusterState says we are the leader (http://127.0.0.1:37291/solr/awhollynewcollection_0_shard1_replica_n1), but locally we don't think so. Request came from null at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413) at org.apache.solr.client.solrj.impl.CloudSolrClient.lambda$directUpdate$0(CloudSolrClient.java:527) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ... 1 more FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testEventQueue Error Message: The TriggerAction should have been created by now Stack Trace: java.lang.AssertionError: The TriggerAction should have been created by now at __randomizedtesting.SeedInfo.seed([43CAB3C5B0A06BB3:8A7FF16BB9C7AD46]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testEventQueue(TestTriggerIntegration.java:618) 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 11692 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration [junit4] 2> 6303 INFO (SUITE-TestTriggerIntegration-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_43CAB3C5B0A06BB3-001/init-core-data-001 [junit4] 2> 6305 WARN (SUITE-TestTriggerIntegration-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1 [junit4] 2> 6306 INFO (SUITE-TestTriggerIntegration-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 6307 INFO (SUITE-TestTriggerIntegration-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 6324 INFO (SUITE-TestTriggerIntegration-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI) [junit4] 2> 6361 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue [junit4] 2> 6364 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6364 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6402 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6403 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6418 DEBUG (simCloudManagerPool-99-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6425 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 6470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 6470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 6470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 6470 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6473 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated [junit4] 2> 6473 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6473 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventQueueAction}], enabled=true} [junit4] 2> 6479 INFO (TEST-TestTriggerIntegration.testEventQueue-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestTriggerIntegration -Dtests.method=testEventQueue -Dtests.seed=43CAB3C5B0A06BB3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es-BO -Dtests.timezone=Etc/Zulu -Dtests.asserts=true -Dtests.file.encoding=UTF-8 [junit4] FAILURE 0.13s J1 | TestTriggerIntegration.testEventQueue <<< [junit4] > Throwable #1: java.lang.AssertionError: The TriggerAction should have been created by now [junit4] > at __randomizedtesting.SeedInfo.seed([43CAB3C5B0A06BB3:8A7FF16BB9C7AD46]:0) [junit4] > at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testEventQueue(TestTriggerIntegration.java:618) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] 2> 6494 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState [junit4] 2> 6495 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 6495 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6503 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6504 DEBUG (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6504 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted [junit4] 2> java.lang.InterruptedException [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 6504 DEBUG (ScheduledTrigger-102-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 6525 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6521 DEBUG (simCloudManagerPool-99-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6526 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 6526 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr] [junit4] 2> 6526 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion -1 [junit4] 2> 6526 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 6527 DEBUG (simCloudManagerPool-99-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6527 DEBUG (simCloudManagerPool-99-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 6534 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6534 DEBUG (simCloudManagerPool-99-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr] [junit4] 2> 6534 DEBUG (simCloudManagerPool-99-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr] [junit4] 2> 6538 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 5 [junit4] 2> 6538 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 6541 DEBUG (ScheduledTrigger-104-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 6539 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 6551 DEBUG (ScheduledTrigger-104-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 6551 DEBUG (ScheduledTrigger-104-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10002_solr [junit4] 2> 6554 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6554 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 6561 DEBUG (ScheduledTrigger-104-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 6569 DEBUG (simCloudManagerPool-99-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6569 DEBUG (simCloudManagerPool-99-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 6569 DEBUG (simCloudManagerPool-99-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6569 DEBUG (simCloudManagerPool-99-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6569 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 6570 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 6570 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6570 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 6570 DEBUG (ScheduledTrigger-104-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 6570 DEBUG (ScheduledTrigger-104-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10002_solr] [junit4] 2> 6571 DEBUG (ScheduledTrigger-104-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc6de1bc7236T21rsbvng4wu7nyyt078n77wgq", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":1333080031523382, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333080031523382], [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 6579 DEBUG (AutoscalingActionExecutor-105-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc6de1bc7236T21rsbvng4wu7nyyt078n77wgq", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":1333080031523382, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333080031523382], [junit4] 2> "_enqueue_time_":1333081018272832, [junit4] 2> "nodeNames":["127.0.0.1:10002_solr"]}} [junit4] 2> 6580 INFO (TEST-TestTriggerIntegration.testNodeLostTriggerRestoreState-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState [junit4] 2> 6583 INFO (TEST-TestTriggerIntegration.testListeners-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testListeners [junit4] 2> 6583 DEBUG (TEST-TestTriggerIntegration.testListeners-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 6583 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 6583 INFO (TEST-TestTriggerIntegration.testListeners-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6587 WARN (AutoscalingActionExecutor-105-thread-1) [ ] o.a.s.c.a.SystemLogListener Exception sending event to collection .system [junit4] 2> java.io.IOException: java.lang.InterruptedException [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:430) [junit4] 2> at org.apache.solr.cloud.autoscaling.SystemLogListener.onEvent(SystemLogListener.java:122) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:744) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$TriggerListeners.fireListeners(ScheduledTriggers.java:714) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:340) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> Caused by: java.lang.InterruptedException [junit4] 2> at java.util.concurrent.FutureTask.awaitDone(FutureTask.java:404) [junit4] 2> at java.util.concurrent.FutureTask.get(FutureTask.java:191) [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.SimCloudManager.request(SimCloudManager.java:428) [junit4] 2> ... 10 more [junit4] 2> 6587 DEBUG (AutoscalingActionExecutor-105-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 413 ms for event id=4bc6de1bc7236T21rsbvng4wu7nyyt078n77wgq [junit4] 2> 6587 DEBUG (TEST-TestTriggerIntegration.testListeners-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6587 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6588 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted [junit4] 2> java.lang.InterruptedException [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion -1 [junit4] 2> 6588 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9 [junit4] 2> 6591 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6591 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9 [junit4] 2> 6591 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 6591 DEBUG (simCloudManagerPool-99-thread-6) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6592 DEBUG (simCloudManagerPool-99-thread-6) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 6592 DEBUG (simCloudManagerPool-99-thread-6) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6592 DEBUG (simCloudManagerPool-99-thread-6) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6592 DEBUG (simCloudManagerPool-99-thread-6) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestDummyAction}], enabled=true} [junit4] 2> 6592 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 6592 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 6593 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 6593 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6593 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 6594 DEBUG (simCloudManagerPool-99-thread-7) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6594 DEBUG (simCloudManagerPool-99-thread-7) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11 [junit4] 2> 6594 DEBUG (simCloudManagerPool-99-thread-7) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6594 DEBUG (simCloudManagerPool-99-thread-7) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6595 DEBUG (simCloudManagerPool-99-thread-7) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestDummyAction}], enabled=true} [junit4] 2> 6595 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11 [junit4] 2> 6595 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11 [junit4] 2> 6595 DEBUG (simCloudManagerPool-99-thread-8) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6596 DEBUG (simCloudManagerPool-99-thread-8) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12 [junit4] 2> 6596 DEBUG (simCloudManagerPool-99-thread-8) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6596 DEBUG (simCloudManagerPool-99-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr] [junit4] 2> 6596 DEBUG (simCloudManagerPool-99-thread-8) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestDummyAction}], enabled=true} [junit4] 2> 6596 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12 [junit4] 2> 6596 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 12, lastZnodeVersion 12 [junit4] 2> 6611 DEBUG (ScheduledTrigger-106-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 6614 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6614 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 6614 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 1333083178942982 [junit4] 2> 6632 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 6634 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6634 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 6634 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [1333083178942982], now=1333084199886732 [junit4] 2> 6635 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc6e9d564206T21rsbvng4wu7nyyt078n77wgt", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333083178942982, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333083178942982], [junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}} [junit4] 2> 6636 DEBUG (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc6e9d564206T21rsbvng4wu7nyyt078n77wgt", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333083178942982, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333083178942982], [junit4] 2> "_enqueue_time_":1333084211637132, [junit4] 2> "nodeNames":["127.0.0.1:10003_solr"]}} [junit4] 2> 6637 DEBUG (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 40 ms for event id=4bc6e9d564206T21rsbvng4wu7nyyt078n77wgt [junit4] 2> 6652 DEBUG (ScheduledTrigger-106-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 6656 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6656 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 6672 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 6677 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6677 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 6692 DEBUG (ScheduledTrigger-106-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6697 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6697 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6697 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10004_solr at time 1333087324347032 [junit4] 2> 6713 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6717 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6717 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6717 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [1333087324347032], now=1333088342889832 [junit4] 2> 6718 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"4bc6f946c1a98T21rsbvng4wu7nyyt078n77wgw", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333087324347032, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333087324347032], [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 6733 DEBUG (ScheduledTrigger-106-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6752 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6752 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6752 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [1333087324347032], now=1333090068189682 [junit4] 2> 6752 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc6f946c1a98T21rsbvng4wu7nyyt078n77wgy", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333087324347032, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333087324347032], [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 6753 DEBUG (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc6f946c1a98T21rsbvng4wu7nyyt078n77wgy", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333087324347032, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333087324347032], [junit4] 2> "_enqueue_time_":1333090077762332, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> 6753 INFO (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.ActionThrottle The last action attempt started 5841ms ago. [junit4] 2> 6754 WARN (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Exception executing actions [junit4] 2> java.lang.Exception: Error executing action: test1 for trigger event: { [junit4] 2> "id":"4bc6f946c1a98T21rsbvng4wu7nyyt078n77wgy", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333087324347032, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333087324347032], [junit4] 2> "_enqueue_time_":1333090077762332, [junit4] 2> "nodeNames":["127.0.0.1:10004_solr"]}} [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:330) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> Caused by: java.lang.RuntimeException: failure [junit4] 2> at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestDummyAction.process(TestTriggerIntegration.java:890) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:327) [junit4] 2> ... 6 more [junit4] 2> 6754 DEBUG (AutoscalingActionExecutor-107-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 69 ms for event id=4bc6f946c1a98T21rsbvng4wu7nyyt078n77wgy [junit4] 2> 6773 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6773 DEBUG (ScheduledTrigger-106-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6773 DEBUG (ScheduledTrigger-106-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6793 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 6793 DEBUG (ScheduledTrigger-106-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6793 DEBUG (ScheduledTrigger-106-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6793 INFO (TEST-TestTriggerIntegration.testListeners-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testListeners [junit4] 2> 6796 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCooldown [junit4] 2> 6796 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13 [junit4] 2> 6796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13 [junit4] 2> 6796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 6796 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6796 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6796 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted [junit4] 2> java.lang.InterruptedException [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 6796 DEBUG (TEST-TestTriggerIntegration.testCooldown-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14 [junit4] 2> 6797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 6797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion -1 [junit4] 2> 6797 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14 [junit4] 2> 6798 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6798 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14 [junit4] 2> 6798 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 4 [junit4] 2> 6798 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6799 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6800 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15 [junit4] 2> 6801 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 6801 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 6801 DEBUG (simCloudManagerPool-99-thread-14) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 6801 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15 [junit4] 2> 6801 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init [junit4] 2> 6803 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15 [junit4] 2> 6803 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6803 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 6803 DEBUG (simCloudManagerPool-99-thread-15) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 6803 DEBUG (simCloudManagerPool-99-thread-15) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 16 [junit4] 2> 6803 DEBUG (simCloudManagerPool-99-thread-15) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 6803 DEBUG (simCloudManagerPool-99-thread-15) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true} [junit4] 2> 6804 DEBUG (simCloudManagerPool-99-thread-15) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr] [junit4] 2> 6804 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 16 [junit4] 2> 6804 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 16, lastZnodeVersion 16 [junit4] 2> 6818 DEBUG (ScheduledTrigger-108-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5 [junit4] 2> 6823 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6823 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 6823 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10005_solr at time 1333093630978682 [junit4] 2> 6838 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5 [junit4] 2> 6843 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6843 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 6843 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10005_solr] added at times [1333093630978682], now=1333094647987382 [junit4] 2> 6844 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc710c53aa7aT21rsbvng4wu7nyyt078n77wh1", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333093630978682, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333093630978682], [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 6844 DEBUG (AutoscalingActionExecutor-109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc710c53aa7aT21rsbvng4wu7nyyt078n77wh1", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333093630978682, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333093630978682], [junit4] 2> "_enqueue_time_":1333094657100382, [junit4] 2> "nodeNames":["127.0.0.1:10005_solr"]}} [junit4] 2> 6845 DEBUG (AutoscalingActionExecutor-109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 24 ms for event id=4bc710c53aa7aT21rsbvng4wu7nyyt078n77wh1 [junit4] 2> 6859 DEBUG (ScheduledTrigger-108-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 5 [junit4] 2> 6864 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6864 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 6879 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6885 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6885 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6885 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10006_solr at time 1333096712997832 [junit4] 2> 6899 DEBUG (ScheduledTrigger-108-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6905 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6905 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6905 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [1333096712997832], now=1333097726590632 [junit4] 2> 6905 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"4bc71c4078bc8T21rsbvng4wu7nyyt078n77wh4", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333096712997832, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333096712997832], [junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} [junit4] 2> 6919 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6926 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6926 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6926 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [1333096712997832], now=1333098767858632 [junit4] 2> 6926 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"4bc71c4078bc8T21rsbvng4wu7nyyt078n77wh6", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333096712997832, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333096712997832], [junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} [junit4] 2> 6939 DEBUG (ScheduledTrigger-108-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6946 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6947 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6947 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_cooldown_trigger firing registered processor for nodes: [127.0.0.1:10006_solr] added at times [1333096712997832], now=1333099805175682 [junit4] 2> 6947 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc71c4078bc8T21rsbvng4wu7nyyt078n77wh8", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333096712997832, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333096712997832], [junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} [junit4] 2> 6947 DEBUG (AutoscalingActionExecutor-109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc71c4078bc8T21rsbvng4wu7nyyt078n77wh8", [junit4] 2> "source":"node_added_cooldown_trigger", [junit4] 2> "eventTime":1333096712997832, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333096712997832], [junit4] 2> "_enqueue_time_":1333099813959782, [junit4] 2> "nodeNames":["127.0.0.1:10006_solr"]}} [junit4] 2> 6947 INFO (AutoscalingActionExecutor-109-thread-1) [ ] o.a.s.c.ActionThrottle The last action attempt started 5149ms ago. [junit4] 2> 6948 DEBUG (AutoscalingActionExecutor-109-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event id=4bc71c4078bc8T21rsbvng4wu7nyyt078n77wh8 [junit4] 2> 6960 DEBUG (ScheduledTrigger-108-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6968 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6968 DEBUG (ScheduledTrigger-108-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6980 DEBUG (ScheduledTrigger-108-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 6988 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_cooldown_trigger [junit4] 2> 6988 DEBUG (ScheduledTrigger-108-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 6988 INFO (TEST-TestTriggerIntegration.testCooldown-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testCooldown [junit4] 2> 6991 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeMarkersRegistration [junit4] 2> 6991 DEBUG (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 17 [junit4] 2> 6991 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 17 [junit4] 2> 6991 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 6991 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6991 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6991 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted [junit4] 2> java.lang.InterruptedException [junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220) [junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335) [junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 6991 DEBUG (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6992 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 6992 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.TestTriggerIntegration ====== KILL OVERSEER 1 [junit4] 2> 6992 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 6992 DEBUG (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 18 [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion -1 [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 18 [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10000_solr [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 6993 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 18, lastZnodeVersion 18 [junit4] 2> 6993 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7013 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7034 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7054 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7074 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7093 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.TestTriggerIntegration ====== ADD TRIGGERS [junit4] 2> 7094 DEBUG (simCloudManagerPool-99-thread-22) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 7094 DEBUG (simCloudManagerPool-99-thread-22) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 19 [junit4] 2> 7095 DEBUG (simCloudManagerPool-99-thread-22) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7095 DEBUG (simCloudManagerPool-99-thread-22) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7095 DEBUG (simCloudManagerPool-99-thread-22) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventMarkerAction}], enabled=true} [junit4] 2> 7095 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 19 [junit4] 2> 7095 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventMarkerAction init [junit4] 2> 7095 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 19, lastZnodeVersion 19 [junit4] 2> 7100 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7100 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7100 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 7101 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 7101 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 20 [junit4] 2> 7101 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7101 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7102 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7102 DEBUG (simCloudManagerPool-99-thread-23) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventMarkerAction}], enabled=true} [junit4] 2> 7102 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 20 [junit4] 2> 7102 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventMarkerAction init [junit4] 2> 7102 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 20, lastZnodeVersion 20 [junit4] 2> 7102 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 6 [junit4] 2> 7102 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.TestTriggerIntegration ====== ADD NODE 1 [junit4] 2> 7120 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 7 [junit4] 2> 7121 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7121 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 7 [junit4] 2> 7121 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10008_solr at time 1333108525046282 [junit4] 2> 7122 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 7 [junit4] 2> 7141 DEBUG (ScheduledTrigger-112-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 7 [junit4] 2> 7141 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7141 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 7 [junit4] 2> 7141 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10008_solr] added at times [1333108525046282], now=1333109537623782 [junit4] 2> 7141 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc7484151a0aT21rsbvng4wu7nyyt078n77whb", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333108525046282, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333108525046282], [junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}} [junit4] 2> 7142 DEBUG (AutoscalingActionExecutor-113-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc7484151a0aT21rsbvng4wu7nyyt078n77whb", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1333108525046282, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333108525046282], [junit4] 2> "_enqueue_time_":1333109544606682, [junit4] 2> "nodeNames":["127.0.0.1:10008_solr"]}} [junit4] 2> 7143 DEBUG (AutoscalingActionExecutor-113-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 34 ms for event id=4bc7484151a0aT21rsbvng4wu7nyyt078n77whb [junit4] 2> 7161 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 7 [junit4] 2> 7162 DEBUG (ScheduledTrigger-112-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7162 DEBUG (ScheduledTrigger-112-thread-4) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 7 [junit4] 2> 7163 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 7 [junit4] 2> 7181 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 7 [junit4] 2> 7182 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7182 DEBUG (ScheduledTrigger-112-thread-1) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 7 [junit4] 2> 7183 DEBUG (ScheduledTrigger-112-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 7 [junit4] 2> 7202 DEBUG (ScheduledTrigger-112-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 7 [junit4] 2> 7202 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7202 DEBUG (ScheduledTrigger-112-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 7 [junit4] 2> 7202 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.TestTriggerIntegration ====== KILL OVERSEER 2 [junit4] 2> 7203 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 7203 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 7203 DEBUG (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 7208 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 20 [junit4] 2> 7209 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7209 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestEventMarkerAction}], enabled=true} [junit4] 2> 7210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 20, lastZnodeVersion -1 [junit4] 2> 7210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 20 [junit4] 2> 7210 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventMarkerAction init [junit4] 2> 7210 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10001_solr [junit4] 2> 7210 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.s.TestTriggerIntegration TestEventMarkerAction init [junit4] 2> 7210 DEBUG (ScheduledTrigger-114-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 6 [junit4] 2> 7210 DEBUG (ScheduledTrigger-114-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr [junit4] 2> 7213 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 7213 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6 [junit4] 2> 7213 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7213 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr [junit4] 2> 7215 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 20, lastZnodeVersion 20 [junit4] 2> 7231 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 6 [junit4] 2> 7231 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10001_solr] [junit4] 2> 7231 DEBUG (ScheduledTrigger-114-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc758e73a3c6T21rsbvng4wu7nyyt078n77whe", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":1333112993981382, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333112993981382], [junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} [junit4] 2> 7234 DEBUG (AutoscalingActionExecutor-115-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc758e73a3c6T21rsbvng4wu7nyyt078n77whe", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":1333112993981382, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1333112993981382], [junit4] 2> "_enqueue_time_":1333114026774482, [junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} [junit4] 2> 7234 INFO (TEST-TestTriggerIntegration.testNodeMarkersRegistration-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeMarkersRegistration [junit4] 2> 7234 DEBUG (AutoscalingActionExecutor-115-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 31 ms for event id=4bc758e73a3c6T21rsbvng4wu7nyyt078n77whe [junit4] 2> 7242 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSearchRate [junit4] 2> 7242 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 21 [junit4] 2> 7242 INFO (TEST-TestTriggerIntegration.testSearchRate-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache... [junit4] 2> 7242 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 7243 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[43CAB3C5B0A06BB3]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 7243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 7243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 22 [junit4] 2> 7243 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7244 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 22, lastZnodeVersion -1 [junit4] 2> 7244 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 22 [junit4] 2> 7246 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 7247 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 22, lastZnodeVersion 22 [junit4] 2> 7247 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7248 DEBUG (simCloudManagerPool-99-thread-28) [ ] o.a.s.c.a.s.SimCloudManager Invoking Collection Action :create with params ?action=CREATE&name=collection1&collection.configName=conf&numShards=1&replicationFactor=2&nrtReplicas=2 [junit4] 2> 7270 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7291 DEBUG (ScheduledTrigger-116-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7307 DEBUG (simCloudManagerPool-99-thread-32) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 7307 DEBUG (simCloudManagerPool-99-thread-32) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 23 [junit4] 2> 7312 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7318 DEBUG (simCloudManagerPool-99-thread-32) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7318 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 23 [junit4] 2> 7318 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 7318 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 23, lastZnodeVersion 23 [junit4] 2> 7319 DEBUG (simCloudManagerPool-99-thread-33) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 7319 DEBUG (simCloudManagerPool-99-thread-33) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 24 [junit4] 2> 7319 DEBUG (simCloudManagerPool-99-thread-33) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10006_solr, 127.0.0.1:10005_solr, 127.0.0.1:10008_solr, 127.0.0.1:10003_solr, 127.0.0.1:10007_solr] [junit4] 2> 7320 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 24 [junit4] 2> 7321 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 7321 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 24, lastZnodeVersion 24 [junit4] 2> 7332 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7352 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7372 DEBUG (ScheduledTrigger-116-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 6 [junit4] 2> 7376 DEBUG (ScheduledTrigger-116-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"4bc76dfe3157eT21rsbvng4wu7nyyt078n77whh", [junit4] 2> "source":"search_rate_trigger", [junit4] 2> "eventTime":1333118655206782, [junit4] 2> "eventType":"SEARCHRATE", [junit4] 2> "properties":{ [junit4] 2> "node":{ [junit4] 2> "127.0.0.1:10006_solr":250.0, [junit4] 2> "127.0.0.1:10003_solr":250.0}, [junit4] 2> "replica":[ [junit4] 2> "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10006_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", [junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10003_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], [junit4] 2> "collection":{"collection1":500.0}, [junit4] 2> "shard":{"collection1":{"shard1":500.0}}}} [junit4] 2> 7388 DEBUG (AutoscalingActionExecutor-117-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"4bc76dfe3157eT21rsbvng4wu7nyyt078n77whh", [junit4] 2> "source":"search_rate_trigger", [junit4] 2> "eventTime":1333118655206782, [junit4] 2> "eventType":"SEARCHRATE", [junit4] 2> "properties":{ [junit4] 2> "node":{ [junit4] 2> "127.0.0.1:10006_solr":250.0, [junit4] 2> "127.0.0.1:10003_solr":250.0}, [junit4] 2> "replica":[ [junit4] 2> "{\"core_node2\":{\n \"core\":\"collection1_shard1_replica_n2\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10006_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}", [junit4] 2> "{\"core_node1\":{\n \"core\":\"collection1_shard1_replica_n1\",\n \"INDEX.sizeInBytes\":123450000,\n \"rate\":250.0,\n \"node_name\":\"127.0.0.1:10003_solr\",\n \"state\":\"active\",\n \"type\":\"NRT\",\n \"QUERY./select.requestTimes:1minRate\":250.0,\n \"shard\":\"shard1\",\n \"collection\":\"collection1\"}}"], [junit4] 2> "collection":{"collection1":500.0}, [junit4] 2> "shard":{"collection1":{"shard1":500.0}}, [junit4] 2> "_enqueue_time_":1333121260241732}} [junit4] 2> 7393 DEBUG (AutoscalingActionExecutor-117-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 332 ms for event id=4bc76dfe3157eT21rsbvng4wu7nyyt078n77whh [junit4] 2> 7407 DEBUG (ScheduledTrigger-116-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"4bc777162f780T21rsbvng4wu7nyyt078n77whk", [junit4] 2> "source":"search_rate_trigger", [junit4] 2> "eventTime":1333121096284032, [junit4] 2> "eventType":"SEARCHRATE", [junit4] 2> "properties":{ [junit4] 2> "node":{ [junit4] 2> "127.0.0.1:10006_solr":250.0, [junit4] 2> "127.0.0.1:10003_solr":250.0}, [junit4] 2> "replica":[ [junit4] [...truncated too long message...] ] 2> 1368106 WARN (OverseerAutoScalingTriggerThread-99197384662056965-127.0.0.1:42191_solr-n_0000000001) [n:127.0.0.1:42191_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 1368107 INFO (jetty-closer-148-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4904aa1c{/solr,null,UNAVAILABLE} [junit4] 2> 1368109 INFO (zkCallback-183-thread-4-processing-n:127.0.0.1:41551_solr) [n:127.0.0.1:41551_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41551_solr [junit4] 2> 1368130 ERROR (qtp168734593-623) [n:127.0.0.1:42191_solr ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: Solr is shutting down [junit4] 2> at org.apache.solr.handler.admin.PrepRecoveryOp.execute(PrepRecoveryOp.java:171) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:384) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:389) [junit4] 2> at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) [junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:177) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:736) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:717) [junit4] 2> at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:498) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:382) [junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:326) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:139) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) [junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) [junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) [junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) [junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) [junit4] 2> at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:493) [junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) [junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:534) [junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) [junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) [junit4] 2> at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283) [junit4] 2> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:108) [junit4] 2> at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) [junit4] 2> at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) [junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> [junit4] 2> 1368130 INFO (qtp168734593-623) [n:127.0.0.1:42191_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:41551_solr&onlyIfLeaderActive=true&core=oldindextest_shard1_replica_n3&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=400 QTime=93034 [junit4] 2> 1373089 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.c.RecoveryStrategy RecoveryStrategy has been closed [junit4] 2> 1373090 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.c.RecoveryStrategy Finished recovery process, successful=[false] [junit4] 2> 1373090 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.c.SolrCore [oldindextest_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@6739414e [junit4] 2> 1373090 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.oldindextest.shard1.replica_n1, tag=1731805518 [junit4] 2> 1373090 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@432f090d: rootName = solr_41551, domain = solr.core.oldindextest.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.oldindextest.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@4f684a50 [junit4] 2> 1373094 INFO (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.oldindextest.shard1.leader, tag=1731805518 [junit4] 2> 1373095 WARN (recoveryExecutor-180-thread-1-processing-n:127.0.0.1:41551_solr x:oldindextest_shard1_replica_n1 s:shard1 c:oldindextest r:core_node2) [n:127.0.0.1:41551_solr c:oldindextest s:shard1 r:core_node2 x:oldindextest_shard1_replica_n1] o.a.s.c.RecoveryStrategy Stopping recovery for core=[oldindextest_shard1_replica_n1] coreNodeName=[core_node2] [junit4] 2> 1373097 INFO (jetty-closer-148-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@13e6c64e{/solr,null,UNAVAILABLE} [junit4] 2> 1373097 ERROR (SUITE-CleanupOldIndexTest-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 1373097 INFO (SUITE-CleanupOldIndexTest-seed#[43CAB3C5B0A06BB3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39121 39121 [junit4] 2> 1378132 INFO (Thread-108) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39121 39121 [junit4] 2> 1378133 WARN (Thread-108) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 4 /solr/aliases.json [junit4] 2> 4 /solr/clusterprops.json [junit4] 2> 3 /solr/security.json [junit4] 2> 3 /solr/configs/conf1 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 16 /solr/collections/oldindextest/state.json [junit4] 2> 4 /solr/clusterstate.json [junit4] 2> 2 /solr/autoscaling.json [junit4] 2> 2 /solr/collections/oldindextest/leader_elect/shard1/election/99197384662056965-core_node4-n_0000000000 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 4 /solr/live_nodes [junit4] 2> 4 /solr/collections [junit4] 2> 2 /solr/overseer/queue-work [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.CleanupOldIndexTest_43CAB3C5B0A06BB3-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1317, maxMBSortInHeap=6.905622008407746, sim=RandomSimilarity(queryNorm=false): {}, locale=sr-Latn-BA, timezone=Africa/Kinshasa [junit4] 2> NOTE: Linux 4.10.0-40-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=346031752,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [PreAnalyzedFieldManagedSchemaCloudTest, JavabinLoaderTest, TestSolrIndexConfig, TestClusterStateProvider, TestRecovery, TolerantUpdateProcessorTest, AnalysisAfterCoreReloadTest, TestBlendedInfixSuggestions, TestFieldCollectionResource, CdcrReplicationHandlerTest, CleanupOldIndexTest] [junit4] Completed [250/763 (3!)] on J0 in 1329.72s, 1 test, 1 error <<< FAILURES! [...truncated 49892 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org