lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-master - Build # 2356 - Still unstable
Date Thu, 22 Feb 2018 03:28:01 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2356/

6 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.ltr.feature.TestExternalValueFeatures

Error Message:
1 thread leaked from SUITE scope at org.apache.solr.ltr.feature.TestExternalValueFeatures:     1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)         at java.lang.Thread.run(Thread.java:748)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.ltr.feature.TestExternalValueFeatures: 
   1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
	at __randomizedtesting.SeedInfo.seed([BFB4FE6E10EE8A02]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.ltr.feature.TestExternalValueFeatures

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)         at java.lang.Thread.run(Thread.java:748)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
	at __randomizedtesting.SeedInfo.seed([BFB4FE6E10EE8A02]:0)


FAILED:  org.apache.solr.cloud.ReplaceNodeNoTargetTest.test

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([B8802F5058FD4B33:30D4108AF60126CB]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertTrue(Assert.java:54)
	at org.apache.solr.cloud.ReplaceNodeNoTargetTest.test(ReplaceNodeNoTargetTest.java:92)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)


FAILED:  org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate

Error Message:
The trigger did not fire at all

Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
	at __randomizedtesting.SeedInfo.seed([B8802F5058FD4B33:E5C831D9973BED7C]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate(TestTriggerIntegration.java:1179)
	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.cdcr.CdcrBootstrapTest.testBootstrapWithContinousIndexingOnSourceCluster

Error Message:
Document mismatch on target after sync expected:<2000> but was:<1901>

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


FAILED:  org.apache.solr.cloud.autoscaling.sim.TestLargeCluster.testSearchRate

Error Message:
The trigger did not fire at all

Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
	at __randomizedtesting.SeedInfo.seed([B8802F5058FD4B33:E5C831D9973BED7C]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.autoscaling.sim.TestLargeCluster.testSearchRate(TestLargeCluster.java:547)
	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 12622 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration
   [junit4]   2> 1662839 INFO  (SUITE-TestTriggerIntegration-seed#[B8802F5058FD4B33]-worker) [    ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_B8802F5058FD4B33-001/init-core-data-001
   [junit4]   2> 1662839 INFO  (SUITE-TestTriggerIntegration-seed#[B8802F5058FD4B33]-worker) [    ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 1662861 INFO  (SUITE-TestTriggerIntegration-seed#[B8802F5058FD4B33]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 1662931 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
   [junit4]   2> 1662932 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
   [junit4]   2> 1662932 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10000_solr]
   [junit4]   2> 1662932 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
   [junit4]   2> 1662932 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
   [junit4]   2> 1662951 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1662951 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
   [junit4]   2> 1662951 DEBUG (ScheduledTrigger-1981-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1662971 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
   [junit4]   2> 1662971 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
   [junit4]   2> 1662971 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
   [junit4]   2> 1662971 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
   [junit4]   2> 1662972 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1662972 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 1662999 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 1662999 WARN  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1663018 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1663039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
   [junit4]   2> 1663039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
   [junit4]   2> 1663039 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> 1663039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
   [junit4]   2> 1663039 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
   [junit4]   2> 1663040 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1663040 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 1663059 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663080 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663100 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663121 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663141 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663155 DEBUG (simCloudManagerPool-1983-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1663155 DEBUG (simCloudManagerPool-1983-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
   [junit4]   2> 1663156 DEBUG (simCloudManagerPool-1983-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663170 DEBUG (simCloudManagerPool-1983-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663170 DEBUG (simCloudManagerPool-1983-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
   [junit4]   2> 1663171 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
   [junit4]   2> 1663171 INFO  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
   [junit4]   2> 1663171 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 1663173 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663173 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663190 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 1663217 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663218 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663218 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663218 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10002_solr at time 1601841420580985
   [junit4]   2> 1663238 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663239 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663239 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663258 DEBUG (ScheduledTrigger-1984-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663259 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663259 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663278 DEBUG (ScheduledTrigger-1984-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663279 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663279 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663279 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:10002_solr] added at times [1601841420580985], now=1601844471124835
   [junit4]   2> 1663280 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"5b0ddc4dc3879T4z9bvk1oicw7qrdzyny3ix5n8",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":1601841420580985,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601841420580985],
   [junit4]   2>     "nodeNames":["127.0.0.1:10002_solr"]}}
   [junit4]   2> 1663280 DEBUG (ScheduledTrigger-1984-thread-2) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
   [junit4]   2> 1663281 DEBUG (AutoscalingActionExecutor-1985-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"5b0ddc4dc3879T4z9bvk1oicw7qrdzyny3ix5n8",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":1601841420580985,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601841420580985],
   [junit4]   2>     "_enqueue_time_":1601844511260235,
   [junit4]   2>     "nodeNames":["127.0.0.1:10002_solr"]}}
   [junit4]   2> 1663301 DEBUG (simCloudManagerPool-1983-thread-3) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1663302 DEBUG (simCloudManagerPool-1983-thread-3) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
   [junit4]   2> 1663340 DEBUG (simCloudManagerPool-1983-thread-3) [    ] 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> 1663340 DEBUG (simCloudManagerPool-1983-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10002_solr]
   [junit4]   2> 1663340 DEBUG (simCloudManagerPool-1983-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
   [junit4]   2> 1663340 DEBUG (AutoscalingActionExecutor-1985-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 1663340 DEBUG (AutoscalingActionExecutor-1985-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
   [junit4]   2> 1663341 DEBUG (AutoscalingActionExecutor-1985-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 2975 ms for event id=5b0ddc4dc3879T4z9bvk1oicw7qrdzyny3ix5n8
   [junit4]   2> 1663341 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
   [junit4]   2> 1663341 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 1663404 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase 
   [junit4]   2> 
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes:		3
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes:	3
   [junit4]   2> 1663405 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes:		0
   [junit4]   2> 1663406 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections:	[]
   [junit4]   2> 1663406 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node:	0
   [junit4]   2> 1663406 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node:	0
   [junit4]   2> 1663406 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas:		0
   [junit4]   2> 1663407 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
   [junit4]   2> 1663407 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- autoscaling        2
   [junit4]   2> 1663407 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- update             2
   [junit4]   2> 1663407 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
   [junit4]   2> 1663408 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
   [junit4]   2> 1663425 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- STARTED         1
   [junit4]   2> 1663425 INFO  (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- SUCCEEDED       1
   [junit4]   2> 1663441 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663441 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger
   [junit4]   2> 1663441 DEBUG (ScheduledTrigger-1984-thread-4) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663443 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
   [junit4]   2> 1663444 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
   [junit4]   2> 1663444 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 1663444 WARN  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1663466 DEBUG (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1663479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
   [junit4]   2> 1663479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
   [junit4]   2> 1663479 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> 1663479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1
   [junit4]   2> 1663479 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
   [junit4]   2> 1663494 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1663494 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 1663494 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663526 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663546 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663567 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663579 DEBUG (simCloudManagerPool-1986-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1663580 DEBUG (simCloudManagerPool-1986-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
   [junit4]   2> 1663580 DEBUG (simCloudManagerPool-1986-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663580 DEBUG (simCloudManagerPool-1986-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=5, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
   [junit4]   2> 1663580 DEBUG (simCloudManagerPool-1986-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663580 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
   [junit4]   2> 1663581 INFO  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
   [junit4]   2> 1663581 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 1663581 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 1663581 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 1663587 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663601 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 1663601 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663601 DEBUG (ScheduledTrigger-1987-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10003_solr at time 1601860564889885
   [junit4]   2> 1663608 DEBUG (ScheduledTrigger-1987-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3
   [junit4]   2> 1663615 DEBUG (simCloudManagerPool-1986-thread-2) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1663615 DEBUG (simCloudManagerPool-1986-thread-2) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8
   [junit4]   2> 1663615 DEBUG (simCloudManagerPool-1986-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr, 127.0.0.1:10003_solr]
   [junit4]   2> 1663615 DEBUG (simCloudManagerPool-1986-thread-2) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger instantiated with properties: {event=nodeAdded, waitFor=0, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
   [junit4]   2> 1663615 DEBUG (simCloudManagerPool-1986-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:10003_solr]
   [junit4]   2> 1663615 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8
   [junit4]   2> 1663616 INFO  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
   [junit4]   2> 1663616 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeAddedTrigger Adding node from marker path: 127.0.0.1:10003_solr
   [junit4]   2> 1663616 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8
   [junit4]   2> 1663616 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 1663616 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663616 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_restore_trigger firing registered processor for nodes: [127.0.0.1:10003_solr] added at times [1601861306680035], now=1601861316000585
   [junit4]   2> 1663617 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"5b0e2662a02e3T4z9bvk1oicw7qrdzyny3ix5nb",
   [junit4]   2>   "source":"node_added_restore_trigger",
   [junit4]   2>   "eventTime":1601861306680035,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601861306680035],
   [junit4]   2>     "nodeNames":["127.0.0.1:10003_solr"]}}
   [junit4]   2> 1663617 DEBUG (ScheduledTrigger-1987-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_restore_trigger]
   [junit4]   2> 1663618 DEBUG (AutoscalingActionExecutor-1988-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"5b0e2662a02e3T4z9bvk1oicw7qrdzyny3ix5nb",
   [junit4]   2>   "source":"node_added_restore_trigger",
   [junit4]   2>   "eventTime":1601861306680035,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601861306680035],
   [junit4]   2>     "_enqueue_time_":1601861385236135,
   [junit4]   2>     "nodeNames":["127.0.0.1:10003_solr"]}}
   [junit4]   2> 1663619 DEBUG (AutoscalingActionExecutor-1988-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 1663619 DEBUG (AutoscalingActionExecutor-1988-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_restore_trigger after 100ms
   [junit4]   2> 1663619 DEBUG (AutoscalingActionExecutor-1988-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 25 ms for event id=5b0e2662a02e3T4z9bvk1oicw7qrdzyny3ix5nb
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase 
   [junit4]   2> 
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes:		3
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes:	3
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes:		0
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections:	[]
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node:	0
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node:	0
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas:		0
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- autoscaling        2
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- update             2
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_restore_trigger
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- STARTED         1
   [junit4]   2> 1663619 INFO  (TEST-TestTriggerIntegration.testNodeAddedTriggerRestoreState-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- SUCCEEDED       1
   [junit4]   2> 1663674 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
   [junit4]   2> 1663674 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9
   [junit4]   2> 1663674 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 1663675 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
   [junit4]   2> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10
   [junit4]   2> 1663676 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> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion -1
   [junit4]   2> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10
   [junit4]   2> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1663676 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10
   [junit4]   2> 1663676 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663689 WARN  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1663697 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663717 DEBUG (ScheduledTrigger-1990-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663737 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663758 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663786 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663790 DEBUG (simCloudManagerPool-1989-thread-1) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1663790 DEBUG (simCloudManagerPool-1989-thread-1) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
   [junit4]   2> 1663790 DEBUG (simCloudManagerPool-1989-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663790 INFO  (simCloudManagerPool-1989-thread-1) [    ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated
   [junit4]   2> 1663791 DEBUG (simCloudManagerPool-1989-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663791 DEBUG (simCloudManagerPool-1989-thread-1) [    ] 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> 1663823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
   [junit4]   2> 1663823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
   [junit4]   2> 1663823 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
   [junit4]   2> 1663824 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1663824 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663824 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:10004_solr at time 1601871695987785
   [junit4]   2> 1663824 DEBUG (ScheduledTrigger-1990-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663844 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1663844 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 1663844 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:10004_solr] added at times [1601871695987785], now=1601872719741235
   [junit4]   2> 1663844 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"]}}
   [junit4]   2> 1663845 DEBUG (ScheduledTrigger-1990-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger1]
   [junit4]   2> 1663845 DEBUG (AutoscalingActionExecutor-1991-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "_enqueue_time_":1601872742163035,
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"]}}
   [junit4]   2> 1663845 INFO  (AutoscalingActionExecutor-1991-thread-1) [    ] o.a.s.c.a.s.TestTriggerIntegration -- event: {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "_enqueue_time_":1601872742163035,
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"]}}
   [junit4]   2> 1663846 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 1663846 WARN  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1663846 DEBUG (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1663846 WARN  (AutoscalingActionExecutor-1991-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Exception executing actions
   [junit4]   2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_trigger1 has been closed.
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.dequeue(ScheduledTriggers.java:522)
   [junit4]   2> 	at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:307)
   [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> 1663846 DEBUG (AutoscalingActionExecutor-1991-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 49 ms for event id=5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663847 INFO  (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestEventQueueAction instantiated
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663847 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> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion -1
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:10001_solr
   [junit4]   2> 1663847 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.s.TestTriggerIntegration TestTriggerAction init
   [junit4]   2> 1663848 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 11, lastZnodeVersion 11
   [junit4]   2> 1663848 DEBUG (ScheduledTrigger-1993-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663848 DEBUG (ScheduledTrigger-1993-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
   [junit4]   2> 1663848 DEBUG (ScheduledTrigger-1993-thread-1) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "_dequeue_time_":1601872898529635,
   [junit4]   2>     "_enqueue_time_":1601872742163035,
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 1663848 DEBUG (ScheduledTrigger-1993-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger1]
   [junit4]   2> 1663849 DEBUG (AutoscalingActionExecutor-1994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "_dequeue_time_":1601872898529635,
   [junit4]   2>     "_enqueue_time_":1601872742163035,
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 1663849 DEBUG (ScheduledTrigger-1993-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1663849 INFO  (AutoscalingActionExecutor-1994-thread-1) [    ] o.a.s.c.a.s.TestTriggerIntegration -- event: {
   [junit4]   2>   "id":"5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1601871695987785,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1601871695987785],
   [junit4]   2>     "_dequeue_time_":1601872898529635,
   [junit4]   2>     "_enqueue_time_":1601872742163035,
   [junit4]   2>     "nodeNames":["127.0.0.1:10004_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 1663849 DEBUG (ScheduledTrigger-1993-thread-1) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 1663850 DEBUG (AutoscalingActionExecutor-1994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
   [junit4]   2> 1663850 DEBUG (AutoscalingActionExecutor-1994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 100ms
   [junit4]   2> 1663850 DEBUG (AutoscalingActionExecutor-1994-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing took 91 ms for event id=5b0e4d16a4449T4z9bvk1oicw7qrdzyny3ix5ne
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase 
   [junit4]   2> 
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes:		2
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes:	2
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes:		1
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		127.0.0.1:10001_solr
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections:	[]
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node:	0
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node:	0
   [junit4]   2> 1663949 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas:		0
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- autoscaling        1
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- update             3
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger1
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- STARTED         2
   [junit4]   2> 1663950 INFO  (TEST-TestTriggerIntegration.testEventQueue-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ##		- SUCCEEDED       1
   [junit4]   2> 1663950 DEBUG (ScheduledTrigger-1993-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663951 DEBUG (ScheduledTrigger-1993-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1663952 DEBUG (ScheduledTrigger-1993-thread-3) [    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 1663953 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Starting testSearchRate
   [junit4]   2> 1663953 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 12
   [junit4]   2> 1663953 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 12
   [junit4]   2> 1663954 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimNodeStateProvider - removing dead node values: 127.0.0.1:10001_solr
   [junit4]   2> 1663954 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
   [junit4]   2> 1663954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
   [junit4]   2> 1663954 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1663954 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:163)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1663954 DEBUG (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 13
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion -1
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 13
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1663955 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 13, lastZnodeVersion 13
   [junit4]   2> 1663955 DEBUG (ScheduledTrigger-1996-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1663976 DEBUG (ScheduledTrigger-1996-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664006 DEBUG (ScheduledTrigger-1996-thread-1) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664047 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664067 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664103 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664124 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664164 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664166 DEBUG (simCloudManagerPool-1995-thread-4) [    ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for collection1 / shard1: {"core_node1":{
   [junit4]   2>     "node_name":"127.0.0.1:10004_solr",
   [junit4]   2>     "core":"collection1_shard1_replica_n1",
   [junit4]   2>     "leader":"true",
   [junit4]   2>     "state":"active",
   [junit4]   2>     "type":"NRT",
   [junit4]   2>     "INDEX.sizeInBytes":1000000000,
   [junit4]   2>     "shard":"shard1",
   [junit4]   2>     "collection":"collection1"}}
   [junit4]   2> 1664189 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664207 DEBUG (simCloudManagerPool-1995-thread-5) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1664207 DEBUG (simCloudManagerPool-1995-thread-5) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 14
   [junit4]   2> 1664209 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664226 DEBUG (simCloudManagerPool-1995-thread-5) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1664229 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664233 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 14
   [junit4]   2> 1664250 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664253 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1664253 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 14, lastZnodeVersion 14
   [junit4]   2> 1664254 DEBUG (simCloudManagerPool-1995-thread-6) [    ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1664254 DEBUG (simCloudManagerPool-1995-thread-6) [    ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 15
   [junit4]   2> 1664254 DEBUG (simCloudManagerPool-1995-thread-6) [    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10004_solr, 127.0.0.1:10000_solr]
   [junit4]   2> 1664270 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664286 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 15
   [junit4]   2> 1664286 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
   [junit4]   2> 1664287 DEBUG (Simulated OverseerAutoScalingTriggerThread) [    ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 15, lastZnodeVersion 15
   [junit4]   2> 1664307 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664339 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664359 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664392 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664420 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664450 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664477 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664501 DEBUG (ScheduledTrigger-1996-thread-4) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664550 DEBUG (ScheduledTrigger-1996-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664571 DEBUG (ScheduledTrigger-1996-thread-2) [    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
   [junit4]   2> 1664577 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"5b0ead71cd397T4z9bvk1oicw7qrdzyny3ix5ni",
   [junit4]   2>   "source":"search_rate_trigger",
   [junit4]   2>   "eventTime":1601897561379735,
   [junit4]   2>   "eventType":"SEARCHRATE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "node":{
   [junit4]   2>       "127.0.0.1:10004_solr":250.0,
   [junit4]   2>       "127.0.0.1:10000_solr":250.0},
   [junit4]   2>     "replica":[
   [junit4]   2>       "{\"core_node1\":{\n    \"core\":\"collection1_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"QUERY./select.requestTimes:1minRate\":250.0,\n    \"shard\":\"shard1\",\n    \"collection\":\"collection1\"}}",
   [junit4]   2>       "{\"core_node2\":{\n    \"core\":\"collection1_shard1_replica_n2\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10000_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>     "requestedOps":[
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}"]}}
   [junit4]   2> 1664577 DEBUG (ScheduledTrigger-1996-thread-3) [    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, search_rate_trigger]
   [junit4]   2> 1664591 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"5b0ead71cd397T4z9bvk1oicw7qrdzyny3ix5ni",
   [junit4]   2>   "source":"search_rate_trigger",
   [junit4]   2>   "eventTime":1601897561379735,
   [junit4]   2>   "eventType":"SEARCHRATE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "node":{
   [junit4]   2>       "127.0.0.1:10004_solr":250.0,
   [junit4]   2>       "127.0.0.1:10000_solr":250.0},
   [junit4]   2>     "replica":[
   [junit4]   2>       "{\"core_node1\":{\n    \"core\":\"collection1_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"QUERY./select.requestTimes:1minRate\":250.0,\n    \"shard\":\"shard1\",\n    \"collection\":\"collection1\"}}",
   [junit4]   2>       "{\"core_node2\":{\n    \"core\":\"collection1_shard1_replica_n2\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10000_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_":1601909378813835,
   [junit4]   2>     "requestedOps":[
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}"]}}
   [junit4]   2> 1664591 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ComputePlanAction -- processing event: {
   [junit4]   2>   "id":"5b0ead71cd397T4z9bvk1oicw7qrdzyny3ix5ni",
   [junit4]   2>   "source":"search_rate_trigger",
   [junit4]   2>   "eventTime":1601897561379735,
   [junit4]   2>   "eventType":"SEARCHRATE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "node":{
   [junit4]   2>       "127.0.0.1:10004_solr":250.0,
   [junit4]   2>       "127.0.0.1:10000_solr":250.0},
   [junit4]   2>     "replica":[
   [junit4]   2>       "{\"core_node1\":{\n    \"core\":\"collection1_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"QUERY./select.requestTimes:1minRate\":250.0,\n    \"shard\":\"shard1\",\n    \"collection\":\"collection1\"}}",
   [junit4]   2>       "{\"core_node2\":{\n    \"core\":\"collection1_shard1_replica_n2\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10000_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_":1601909378813835,
   [junit4]   2>     "requestedOps":[
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}"]}} with context properties: {BEFORE_ACTION=[compute]}
   [junit4]   2> 1664592 INFO  (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10000_solr&type=NRT
   [junit4]   2> 1664593 INFO  (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10004_solr&type=NRT
   [junit4]   2> 1664593 INFO  (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ComputePlanAction Computed Plan: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10004_solr&type=NRT
   [junit4]   2> 1664607 INFO  (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 1601910877 sessionWrapper.createTime 1601910112751285, this.sessionWrapper.createTime 1601910112751285 
   [junit4]   2> 1664608 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ExecutePlanAction -- processing event: {
   [junit4]   2>   "id":"5b0ead71cd397T4z9bvk1oicw7qrdzyny3ix5ni",
   [junit4]   2>   "source":"search_rate_trigger",
   [junit4]   2>   "eventTime":1601897561379735,
   [junit4]   2>   "eventType":"SEARCHRATE",
   [junit4]   2>   "properties":{
   [junit4]   2>     "node":{
   [junit4]   2>       "127.0.0.1:10004_solr":250.0,
   [junit4]   2>       "127.0.0.1:10000_solr":250.0},
   [junit4]   2>     "__start__":1,
   [junit4]   2>     "replica":[
   [junit4]   2>       "{\"core_node1\":{\n    \"core\":\"collection1_shard1_replica_n1\",\n    \"leader\":\"true\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10004_solr\",\n    \"state\":\"active\",\n    \"type\":\"NRT\",\n    \"QUERY./select.requestTimes:1minRate\":250.0,\n    \"shard\":\"shard1\",\n    \"collection\":\"collection1\"}}",
   [junit4]   2>       "{\"core_node2\":{\n    \"core\":\"collection1_shard1_replica_n2\",\n    \"INDEX.sizeInBytes\":1000000000,\n    \"rate\":250.0,\n    \"node_name\":\"127.0.0.1:10000_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_":1601909378813835,
   [junit4]   2>     "requestedOps":[
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}",
   [junit4]   2>       "Op{action=ADDREPLICA, hints={COLL_SHARD={\n  \"first\":\"collection1\",\n  \"second\":\"shard1\"}}}"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica@4210ee12, org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica@1f78789f, org.apache.solr.client.solrj.request.CollectionAdminRequest$AddReplica@7318cbf5], AFTER_ACTION=[compute], BEFORE_ACTION=[compute, execute]}
   [junit4]   2> 1664609 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10000_solr&type=NRT
   [junit4]   2> 1664620 INFO  (simCloudManagerPool-1995-thread-8) [    ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10000_solr for creating new replica
   [junit4]   2> 1664633 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10004_solr&type=NRT
   [junit4]   2> 1664647 INFO  (simCloudManagerPool-1995-thread-12) [    ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica
   [junit4]   2> 1664661 DEBUG (AutoscalingActionExecutor-1997-thread-1) [    ] o.a.s.c.a.ExecutePlanAction Executing operation: action=ADDREPLICA&collection=collection1&shard=shard1&node=127.0.0.1:10004_solr&type=NRT
   [junit4]   2> 1664677 INFO  (simCloudManagerPool-1995-thread-16) [    ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica
   [junit4]   2> 1664691 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.SolrTestCaseJ4 ###Ending testSearchRate
   [junit4]   2> 1664691 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase 
   [junit4]   2> 
   [junit4]   2> 1664691 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 1664691 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
   [junit4]   2> 1664691 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
   [junit4]   2> 
   [junit4]   2> 1664692 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes:		2
   [junit4]   2> 1664692 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes:	0
   [junit4]   2> 1664692 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes:		0
   [junit4]   2> 1664734 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections:	[collection1]
   [junit4]   2> 1664734 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node:	2
   [junit4]   2> 1664734 INFO  (TEST-TestTriggerIntegration.testSearchRate-seed#[B8802F5058FD4B33]) [    ] o.a.s.c.a.s.SimSolrCloudT

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

er Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 40880 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 40965 INFO  (coreCloseExecutor-23-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7a70958c
   [junit4]   2> 40984 INFO  (coreCloseExecutor-23-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=2054198668
   [junit4]   2> 41061 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@25b7f1a{/solr,null,UNAVAILABLE}
   [junit4]   2> 41094 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.e.j.s.session Stopped scavenging
   [junit4]   2> 71102 WARN  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.e.j.u.t.QueuedThreadPool QueuedThreadPool@qtp572864418{STOPPING,8<=8<=10000,i=0,q=1} Couldn't stop Thread[qtp572864418-24,5,TGRP-TestExternalValueFeatures]
   [junit4]   2> 71111 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 71111 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1343444503
   [junit4]   2> 71111 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
   [junit4]   2> 71152 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@126c7a6: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / null
   [junit4]   2> 71152 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
   [junit4]   2> 71152 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@248fe3d0: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / null
   [junit4]   2> 71153 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
   [junit4]   2> 71153 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@55b75394: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / null
   [junit4]   2> 71155 INFO  (coreCloseExecutor-25-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3825bda
   [junit4]   2> 71155 INFO  (coreCloseExecutor-25-thread-1) [    x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=58874842
   [junit4]   2> 71155 INFO  (coreCloseExecutor-25-thread-1) [    x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4fefbb58: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / null
   [junit4]   2> 71180 INFO  (SUITE-TestExternalValueFeatures-seed#[BFB4FE6E10EE8A02]-worker) [    ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
   [junit4]   2> Feb 22, 2018 3:10:36 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> Feb 22, 2018 3:10:57 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.ltr.feature.TestExternalValueFeatures: 
   [junit4]   2>    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2>         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]   2>         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]   2>         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]   2>         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]   2>         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> Feb 22, 2018 3:10:57 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> INFO: Starting to interrupt leaked threads:
   [junit4]   2>    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
   [junit4]   2> Feb 22, 2018 3:11:00 AM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> SEVERE: There are still zombie threads that couldn't be terminated:
   [junit4]   2>    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2>         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]   2>         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]   2>         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]   2>         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]   2>         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@50241075), locale=da, timezone=Asia/Ulan_Bator
   [junit4]   2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=2,free=219890752,total=342884352
   [junit4]   2> NOTE: All tests run in this JVM: [TestExternalValueFeatures]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestExternalValueFeatures -Dtests.seed=BFB4FE6E10EE8A02 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=da -Dtests.timezone=Asia/Ulan_Bator -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J0 | TestExternalValueFeatures (suite) <<<
   [junit4]    > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.ltr.feature.TestExternalValueFeatures: 
   [junit4]    >    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]    >         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]    >         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]    >         at java.lang.Thread.run(Thread.java:748)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([BFB4FE6E10EE8A02]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=24, name=qtp572864418-24, state=TIMED_WAITING, group=TGRP-TestExternalValueFeatures]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]    >         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]    >         at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]    >         at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]    >         at java.lang.Thread.run(Thread.java:748)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([BFB4FE6E10EE8A02]:0)
   [junit4] Completed [30/36 (1!)] on J0 in 97.17s, 2 tests, 2 errors <<< FAILURES!

[...truncated 40921 lines...]

Mime
View raw message