lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-7.x-Linux (64bit/jdk1.8.0_144) - Build # 1012 - Still Unstable!
Date Mon, 18 Dec 2017 22:38:45 GMT
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...]

Mime
View raw message