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