Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21423/
Java: 32bit/jdk1.8.0_162 -client -XX:+UseConcMarkSweepGC

2 tests failed.
FAILED:  
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventFromRestoredState

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([886A180CCD571763:885CACCCE45AB309]: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.autoscaling.TriggerIntegrationTest.testEventFromRestoredState(TriggerIntegrationTest.java:760)
        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.TriggerIntegrationTest.testMetricTrigger

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([886A180CCD571763:32662F8392BFC12C]:0)
        at org.junit.Assert.fail(Assert.java:92)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at org.junit.Assert.assertNull(Assert.java:551)
        at org.junit.Assert.assertNull(Assert.java:562)
        at 
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1575)
        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 14202 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
   [junit4]   2> 3150688 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/init-core-data-001
   [junit4]   2> 3150689 WARN  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=21 numCloses=21
   [junit4]   2> 3150690 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 3150692 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 3150693 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/tempDir-001
   [junit4]   2> 3150693 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3150693 INFO  (Thread-8094) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3150693 INFO  (Thread-8094) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3150695 ERROR (Thread-8094) [    ] o.a.z.s.ZooKeeperServer 
ZKShutdownHandler is not registered, so ZooKeeper server won't take any action 
on ERROR or SHUTDOWN server state changes
   [junit4]   2> 3150793 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:43323
   [junit4]   2> 3150796 INFO  (zkConnectionManagerCallback-5699-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150800 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3150800 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@be4a34{/solr,null,AVAILABLE}
   [junit4]   2> 3150802 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1892f61{/solr,null,AVAILABLE}
   [junit4]   2> 3150805 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4f4431{HTTP/1.1,[http/1.1]}{127.0.0.1:42309}
   [junit4]   2> 3150805 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1b05288{HTTP/1.1,[http/1.1]}{127.0.0.1:43955}
   [junit4]   2> 3150805 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.e.j.s.Server Started @3151988ms
   [junit4]   2> 3150805 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.e.j.s.Server Started @3151988ms
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42309}
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=43955}
   [junit4]   2> 3150806 ERROR (jetty-launcher-5696-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3150806 ERROR (jetty-launcher-5696-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3150806 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3150807 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3150807 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T07:53:33.443Z
   [junit4]   2> 3150807 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T07:53:33.443Z
   [junit4]   2> 3150808 INFO  (zkConnectionManagerCallback-5701-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150808 INFO  (zkConnectionManagerCallback-5703-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150809 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3150809 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3150821 INFO  (jetty-launcher-5696-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43323/solr
   [junit4]   2> 3150822 INFO  (jetty-launcher-5696-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43323/solr
   [junit4]   2> 3150822 INFO  (zkConnectionManagerCallback-5708-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150823 INFO  (zkConnectionManagerCallback-5711-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150825 INFO  
(zkConnectionManagerCallback-5713-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150825 INFO  
(zkConnectionManagerCallback-5715-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3150892 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3150892 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3150893 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:43955_solr
   [junit4]   2> 3150893 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42309_solr
   [junit4]   2> 3150893 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.Overseer Overseer 
(id=72118278654722053-127.0.0.1:43955_solr-n_0000000000) starting
   [junit4]   2> 3150894 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3150894 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3150899 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 3150900 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:43955_solr
   [junit4]   2> 3150900 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 3150906 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:42309_solr]
   [junit4]   2> 3150907 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 3150907 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 3150907 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3150907 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3150908 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3150908 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3150908 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 2
   [junit4]   2> 3151069 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43955.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151087 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43955.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151088 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43955.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151090 INFO  (jetty-launcher-5696-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/tempDir-001/node2/.
   [junit4]   2> 3151117 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42309.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151133 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42309.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151134 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42309.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151136 INFO  (jetty-launcher-5696-thread-1) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/tempDir-001/node1/.
   [junit4]   2> 3151165 INFO  (zkConnectionManagerCallback-5721-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3151169 INFO  (zkConnectionManagerCallback-5725-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3151170 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3151171 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43323/solr ready
   [junit4]   2> 3151188 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
   [junit4]   2> 3151189 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
   [junit4]   2> 3151189 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 2
   [junit4]   2> 3151189 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 2
   [junit4]   2> 3151191 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3151191 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3151191 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 3151199 INFO  (qtp28563936-30626) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3151201 INFO  (qtp2323615-30615) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3151202 DEBUG (qtp28563936-30614) [n:127.0.0.1:42309_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3151202 INFO  (qtp28563936-30614) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=6
   [junit4]   2> 3151202 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 3
   [junit4]   2> 3151203 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3151204 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3151204 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 3
   [junit4]   2> 3151205 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3151206 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3151206 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3151206 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 3151206 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger
   [junit4]   2> 3151206 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3151206 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3151207 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3151207 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3151207 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@e271f1{/solr,null,AVAILABLE}
   [junit4]   2> 3151207 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.AbstractConnector Started 
ServerConnector@131a0aa{HTTP/1.1,[http/1.1]}{127.0.0.1:34671}
   [junit4]   2> 3151208 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.e.j.s.Server Started @3152390ms
   [junit4]   2> 3151208 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=34671}
   [junit4]   2> 3151208 ERROR 
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3151208 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 3151208 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port 
null
   [junit4]   2> 3151208 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3151209 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T07:53:33.844Z
   [junit4]   2> 3151210 INFO  (zkConnectionManagerCallback-5727-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3151211 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3151221 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43323/solr
   [junit4]   2> 3151222 INFO  (zkConnectionManagerCallback-5731-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3151225 INFO  
(zkConnectionManagerCallback-5733-thread-1-processing-n:127.0.0.1:34671_solr) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3151230 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3151232 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3151234 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:34671_solr
   [junit4]   2> 3151235 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3151235 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3151235 INFO  (zkCallback-5724-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3151236 INFO  
(zkCallback-5732-thread-1-processing-n:127.0.0.1:34671_solr) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3151340 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_34671.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151353 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_34671.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151353 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_34671.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3151355 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/tempDir-001/node3/.
   [junit4]   2> 3152208 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger
   [junit4]   2> 3152208 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3152208 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:34671_solr at time 925975281856646
   [junit4]   2> 3153209 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger
   [junit4]   2> 3153209 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3153209 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger firing registered processor for nodes: 
[127.0.0.1:34671_solr] added at times [925975281856646], now=925976282878949
   [junit4]   2> 3153209 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"34a2b6bbef086T34cux1ibx9qzbut918qu3o9sf",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":925975281856646,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925975281856646],
   [junit4]   2>     "nodeNames":["127.0.0.1:34671_solr"]}}
   [junit4]   2> 3153210 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_trigger]
   [junit4]   2> 3153210 INFO  (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3153211 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"34a2b6bbef086T34cux1ibx9qzbut918qu3o9sf",
   [junit4]   2>   "source":"node_added_trigger",
   [junit4]   2>   "eventTime":925975281856646,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925975281856646],
   [junit4]   2>     "_enqueue_time_":925976283680376,
   [junit4]   2>     "nodeNames":["127.0.0.1:34671_solr"]}}
   [junit4]   2> 3153212 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger after 5000ms
   [junit4]   2> 3153212 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=34a2b6bbef086T34cux1ibx9qzbut918qu3o9sf
   [junit4]   2> 3153215 INFO  (qtp4723395-30678) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3153217 INFO  (qtp28563936-30626) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3153219 INFO  (qtp2323615-30625) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3153220 DEBUG (qtp2323615-30627) [n:127.0.0.1:43955_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3153220 INFO  (qtp2323615-30627) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=7
   [junit4]   2> 3153220 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 4
   [junit4]   2> 3153221 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:34671_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3153221 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=1, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3153221 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 4
   [junit4]   2> 3153221 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3153222 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 3155221 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[886A180CCD571763]) [    
] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
   [junit4]   2> 3155243 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
   [junit4]   2> 3155243 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
   [junit4]   2> 3155243 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 5
   [junit4]   2> 3155244 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 5
   [junit4]   2> 3155244 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3155244 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3155245 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 3155250 INFO  (qtp4723395-30678) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155252 INFO  (qtp28563936-30626) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155254 INFO  (qtp2323615-30627) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155254 DEBUG (qtp4723395-30684) [n:127.0.0.1:34671_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3155255 INFO  (qtp4723395-30684) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=7
   [junit4]   2> 3155255 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 6
   [junit4]   2> 3155256 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:34671_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3155256 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3155256 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 6
   [junit4]   2> 3155258 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3155258 INFO  (qtp4723395-30679) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155258 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3155258 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 3155258 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3155258 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3155259 INFO  (qtp28563936-30673) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155260 INFO  (qtp2323615-30625) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3155261 DEBUG (qtp4723395-30683) [n:127.0.0.1:34671_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3155262 INFO  (qtp4723395-30683) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=5
   [junit4]   2> 3155262 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 7
   [junit4]   2> 3155262 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:34671_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3155262 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3155263 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:34671_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3155263 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3155263 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 7
   [junit4]   2> 3155264 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3155265 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3155265 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3155265 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3155265 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 3155265 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3155266 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3155267 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3155267 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3155267 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@c01f09{/solr,null,AVAILABLE}
   [junit4]   2> 3155268 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.AbstractConnector Started 
ServerConnector@e99450{HTTP/1.1,[http/1.1]}{127.0.0.1:36933}
   [junit4]   2> 3155268 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.Server Started @3156451ms
   [junit4]   2> 3155268 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=36933}
   [junit4]   2> 3155268 ERROR 
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3155269 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 3155269 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port 
null
   [junit4]   2> 3155269 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3155269 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T07:53:37.905Z
   [junit4]   2> 3155270 INFO  (zkConnectionManagerCallback-5737-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3155271 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3155282 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43323/solr
   [junit4]   2> 3155284 INFO  (zkConnectionManagerCallback-5741-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3155286 INFO  
(zkConnectionManagerCallback-5743-thread-1-processing-n:127.0.0.1:36933_solr) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3155291 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3155292 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3155294 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:36933_solr
   [junit4]   2> 3155295 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3155295 INFO  (zkCallback-5724-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3155295 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3155295 INFO  
(zkCallback-5732-thread-1-processing-n:127.0.0.1:34671_solr) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3155295 INFO  
(zkCallback-5742-thread-1-processing-n:127.0.0.1:36933_solr) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3155514 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36933.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3155525 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36933.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3155525 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36933.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3155526 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001/tempDir-001/node4/.
   [junit4]   2> 3156260 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3156260 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3156260 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:36933_solr at time 925979334275005
   [junit4]   2> 3156260 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 firing registered processor for nodes: 
[127.0.0.1:36933_solr] added at times [925979334275005], now=925979334320667
   [junit4]   2> 3156260 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"34a2c5d49efbdT34cux1ibx9qzbut918qu3o9sh",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":925979334275005,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925979334275005],
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3156261 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_trigger2, node_added_trigger1]
   [junit4]   2> 3156261 INFO  (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3156262 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"34a2c5d49efbdT34cux1ibx9qzbut918qu3o9sh",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":925979334275005,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925979334275005],
   [junit4]   2>     "_enqueue_time_":925979334523090,
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3156262 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_added_trigger1
   [junit4]   2> 3156263 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger2 after 5000ms
   [junit4]   2> 3156263 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger1 after 5000ms
   [junit4]   2> 3156263 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=34a2c5d49efbdT34cux1ibx9qzbut918qu3o9sh
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:36933_solr at time 925984337397362
   [junit4]   2> 3161263 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:36933_solr] added at times [925984337397362], now=925984337447319
   [junit4]   2> 3161264 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"34a2d877f8672T34cux1ibx9qzbut918qu3o9sj",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":925984337397362,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925984337397362],
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3161264 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_trigger2, node_added_trigger1]
   [junit4]   2> 3161264 INFO  (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3161265 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"34a2d877f8672T34cux1ibx9qzbut918qu3o9sj",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":925984337397362,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925984337397362],
   [junit4]   2>     "_enqueue_time_":925984337659770,
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3161265 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1518162818898000000 current time = 1518162823901000000
   [junit4]   2> real diff: 5003000000
   [junit4]   2>  min diff: 4998000000
   [junit4]   2> 3161265 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_added_trigger2
   [junit4]   2> 3161265 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger2 after 5000ms
   [junit4]   2> 3161266 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger1 after 5000ms
   [junit4]   2> 3161266 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=34a2d877f8672T34cux1ibx9qzbut918qu3o9sj
   [junit4]   2> 3161269 INFO  (qtp4723395-30683) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161271 INFO  (qtp14583219-30712) [n:127.0.0.1:36933_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161274 INFO  (qtp28563936-30624) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161276 INFO  (qtp2323615-30623) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161276 DEBUG (qtp28563936-30622) [n:127.0.0.1:42309_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3161277 INFO  (qtp28563936-30622) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 3161277 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 8
   [junit4]   2> 3161278 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161278 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3161278 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161278 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161278 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3161278 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 8
   [junit4]   2> 3161280 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3161280 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 8, lastZnodeVersion 8
   [junit4]   2> 3161281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 4
   [junit4]   2> 3161282 INFO  (qtp4723395-30682) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161284 INFO  (qtp14583219-30718) [n:127.0.0.1:36933_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161287 INFO  (qtp28563936-30674) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161290 INFO  (qtp2323615-30615) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3161290 DEBUG (qtp2323615-30617) [n:127.0.0.1:43955_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3161291 INFO  (qtp2323615-30617) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 3161291 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 9
   [junit4]   2> 3161291 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161291 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3161292 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161292 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161292 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3161292 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:36933_solr, 127.0.0.1:34671_solr, 
127.0.0.1:42309_solr]
   [junit4]   2> 3161292 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 9
   [junit4]   2> 3161294 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3161294 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 9, lastZnodeVersion 9
   [junit4]   2> 3161295 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 4
   [junit4]   2> 3161295 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.AbstractConnector Stopped 
ServerConnector@e99450{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 3161295 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=23282700
   [junit4]   2> 3161295 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 3161295 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@16115db: rootName = 
solr_36933, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@15a437
   [junit4]   2> 3161302 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 3161302 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@d119b8: rootName = 
solr_36933, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@1df60b3
   [junit4]   2> 3161308 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 3161308 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@eaca07: rootName = 
solr_36933, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@1d6580d
   [junit4]   2> 3161309 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:36933_solr
   [junit4]   2> 3161310 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.cluster, tag=null
   [junit4]   2> 3161310 INFO  
(zkCallback-5742-thread-1-processing-n:127.0.0.1:36933_solr) 
[n:127.0.0.1:36933_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3161310 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3161311 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 3161310 INFO  (zkCallback-5724-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3161311 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3161311 INFO  
(zkCallback-5732-thread-1-processing-n:127.0.0.1:34671_solr) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3161312 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@c01f09{/solr,null,UNAVAILABLE}
   [junit4]   2> 3161312 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.e.j.s.session Stopped scavenging
   [junit4]   2> 3162281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3162281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 
127.0.0.1:36933_solr
   [junit4]   2> 3162281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:36933_solr]
   [junit4]   2> 3162281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"34a2dc42a4ecbT34cux1ibx9qzbut918qu3o9sl",
   [junit4]   2>   "source":"node_lost_trigger1",
   [junit4]   2>   "eventTime":925985355222731,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925985355222731],
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3162281 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1, 
node_added_trigger1]
   [junit4]   2> 3162282 INFO  (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3162282 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"34a2dc42a4ecbT34cux1ibx9qzbut918qu3o9sl",
   [junit4]   2>   "source":"node_lost_trigger1",
   [junit4]   2>   "eventTime":925985355222731,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925985355222731],
   [junit4]   2>     "_enqueue_time_":925985355438467,
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3162282 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_lost_trigger1
   [junit4]   2> 3162283 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_lost_trigger2 after 5000ms
   [junit4]   2> 3162283 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger2 after 5000ms
   [junit4]   2> 3162283 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_lost_trigger1 after 5000ms
   [junit4]   2> 3162283 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger1 after 5000ms
   [junit4]   2> 3162283 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=34a2dc42a4ecbT34cux1ibx9qzbut918qu3o9sl
   [junit4]   2> 3167285 DEBUG (ScheduledTrigger-10317-thread-3) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3167285 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3167285 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3167285 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3167285 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3167286 DEBUG (ScheduledTrigger-10317-thread-1) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3167286 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 
127.0.0.1:36933_solr
   [junit4]   2> 3167286 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:36933_solr]
   [junit4]   2> 3167286 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"34a2eee77abe7T34cux1ibx9qzbut918qu3o9sn",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":925990359903207,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925990359903207],
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3167286 DEBUG (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1, 
node_added_trigger1]
   [junit4]   2> 3167287 INFO  (ScheduledTrigger-10317-thread-2) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3167287 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"34a2eee77abe7T34cux1ibx9qzbut918qu3o9sn",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":925990359903207,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[925990359903207],
   [junit4]   2>     "_enqueue_time_":925990360196447,
   [junit4]   2>     "nodeNames":["127.0.0.1:36933_solr"]}}
   [junit4]   2> 3167287 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1518162824918000000 current time = 1518162829923000000
   [junit4]   2> real diff: 5005000000
   [junit4]   2>  min diff: 4998000000
   [junit4]   2> 3167287 INFO  
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_lost_trigger2
   [junit4]   2> 3167287 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[886A180CCD571763]) [   
 ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
   [junit4]   2> 3167288 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_lost_trigger2 after 5000ms
   [junit4]   2> 3167288 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger2 after 5000ms
   [junit4]   2> 3167288 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_lost_trigger1 after 5000ms
   [junit4]   2> 3167288 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_trigger1 after 5000ms
   [junit4]   2> 3167288 DEBUG 
(AutoscalingActionExecutor-10318-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=34a2eee77abe7T34cux1ibx9qzbut918qu3o9sn
   [junit4]   2> 3167310 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
   [junit4]   2> 3167310 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode 
version 10
   [junit4]   2> 3167311 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 10
   [junit4]   2> 3167311 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 10
   [junit4]   2> 3167313 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3167313 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3167313 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 10, lastZnodeVersion 10
   [junit4]   2> 3167317 INFO  (qtp4723395-30683) [n:127.0.0.1:34671_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3167319 INFO  (qtp28563936-30622) [n:127.0.0.1:42309_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3167321 INFO  (qtp2323615-30705) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
 status=0 QTime=0
   [junit4]   2> 3167322 DEBUG (qtp2323615-30623) [n:127.0.0.1:43955_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3167322 INFO  (qtp2323615-30623) [n:127.0.0.1:43955_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=7
   [junit4]   2> 3167323 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 11
   [junit4]   2> 3167323 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:43955_solr, 127.0.0.1:34671_solr, 127.0.0.1:42309_solr]
   [junit4]   2> 3167323 DEBUG 
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] 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.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3167323 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 11
   [junit4]   2> 3167323 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T23:27:37+02:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3167324 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3167324 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3167324 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3167324 INFO  
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3167325 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@65ca47{/solr,null,AVAILABLE}
   [junit4]   2> 3167325 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3167325 DEBUG 
(OverseerAutoScalingTriggerThread-72118278654722053-127.0.0.1:43955_solr-n_0000000000)
 [n:127.0.0.1:43955_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 11, lastZnodeVersion 11
   [junit4]   2> 3167325 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 3167325 DEBUG (ScheduledTrigger-10317-thread-4) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3167325 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.AbstractConnector Started 
ServerConnector@1b9639{HTTP/1.1,[http/1.1]}{127.0.0.1:42207}
   [junit4]   2> 3167325 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.e.j.s.Server Started @3168508ms
   [junit4]   2> 3167325 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42207}
   [junit4]   2> 3167325 ERROR 
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging 
may be missing or incomplete.
   [junit4]   2> 3167326 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? 
version 8.0.0
   [junit4]   2> 3167326 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on 
port null
   [junit4]   2> 3167326 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3167326 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T07:53:49.962Z
   [junit4]   2> 3167327 INFO  (zkConnectionManagerCallback-5747-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3167328 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3167344 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43323/solr
   [junit4]   2> 3167345 INFO  (zkConnectionManagerCallback-5751-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3167348 INFO  
(zkConnectionManagerCallback-5753-thread-1-processing-n:127.0.0.1:42207_solr) 
[n:127.0.0.1:42207_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3167352 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3167354 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3167355 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42207_solr
   [junit4]   2> 3167356 INFO  
(zkCallback-5712-thread-1-processing-n:127.0.0.1:43955_solr) 
[n:127.0.0.1:43955_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3167356 INFO  
(zkCallback-5714-thread-1-processing-n:127.0.0.1:42309_solr) 
[n:127.0.0.1:42309_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3167356 INFO  (zkCallback-5724-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3167356 INFO  
(zkCallback-5732-thread-1-processing-n:127.0.0.1:34671_solr) 
[n:127.0.0.1:34671_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3167357 INFO  
(zkCallback-5752-thread-1-processing-n:127.0.0.1:42207_solr) 
[n:127.0.0.1:42207_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3167446 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42207.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3167458 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42207.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@15958f0
   [junit4]   2> 3167458 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[886A180CCD571763])
 [n:127.0.0.1:42207_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42207.

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

 [n:127.0.0.1:42081_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch 
triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for 
/live_nodes]
   [junit4]   2> 3329170 INFO  (jetty-closer-5697-thread-7) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1bab564{/solr,null,UNAVAILABLE}
   [junit4]   2> 3329171 INFO  (jetty-closer-5697-thread-7) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3329180 WARN  
(zkCallback-5878-thread-1-processing-n:127.0.0.1:34551_solr) 
[n:127.0.0.1:34551_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 3329180 WARN  
(zkCallback-5795-thread-1-processing-n:127.0.0.1:37295_solr) 
[n:127.0.0.1:37295_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 3329181 INFO  (jetty-closer-5697-thread-11) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@e79d81{/solr,null,UNAVAILABLE}
   [junit4]   2> 3329181 INFO  (jetty-closer-5697-thread-11) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3329181 INFO  (jetty-closer-5697-thread-4) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@1622488{/solr,null,UNAVAILABLE}
   [junit4]   2> 3329182 INFO  (jetty-closer-5697-thread-4) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3329195 INFO  (jetty-closer-5697-thread-6) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@19d593c{/solr,null,UNAVAILABLE}
   [junit4]   2> 3329196 INFO  (jetty-closer-5697-thread-6) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3329196 ERROR 
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper 
server won't take any action on ERROR or SHUTDOWN server state changes
   [junit4]   2> 3329197 INFO  
(SUITE-TriggerIntegrationTest-seed#[886A180CCD571763]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:43323 43323
   [junit4]   2> 3334220 INFO  (Thread-8094) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:43323 43323
   [junit4]   2> 3334222 WARN  (Thread-8094) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        42      /solr/collections/collection1/terms/shard1
   [junit4]   2>        21      /solr/clusterprops.json
   [junit4]   2>        21      /solr/aliases.json
   [junit4]   2>        20      /solr/security.json
   [junit4]   2>        8       /solr/configs/conf
   [junit4]   2>        2       /solr/collections/testMetricTrigger/terms/shard1
   [junit4]   2>        2       /solr/collections/testMetricTrigger/terms/shard2
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        144     /solr/collections/collection1/state.json
   [junit4]   2>        21      /solr/clusterstate.json
   [junit4]   2>        11      /solr/collections/testMetricTrigger/state.json
   [junit4]   2>        5       /solr/autoscaling.json
   [junit4]   2>        4       
/solr/overseer_elect/election/72118278654722089-127.0.0.1:45535_solr-n_0000000012
   [junit4]   2>        3       
/solr/collections/collection1/leader_elect/shard1/election/72118278654722068-core_node6-n_0000000002
   [junit4]   2>        2       
/solr/overseer_elect/election/72118278654722071-127.0.0.1:34373_solr-n_0000000006
   [junit4]   2>        2       
/solr/overseer_elect/election/72118278654722059-127.0.0.1:34671_solr-n_0000000002
   [junit4]   2>        2       
/solr/overseer_elect/election/72118278654722077-127.0.0.1:37295_solr-n_0000000008
   [junit4]   2>        2       
/solr/collections/collection1/leader_elect/shard1/election/72118278654722059-core_node10-n_0000000004
   [junit4]   2>        2       
/solr/collections/collection1/leader_elect/shard1/election/72118278654722071-core_node4-n_0000000000
   [junit4]   2>        2       
/solr/overseer_elect/election/72118278654722083-127.0.0.1:39583_solr-n_0000000010
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        21      /solr/live_nodes
   [junit4]   2>        21      /solr/collections
   [junit4]   2>        5       /solr/overseer/queue-work
   [junit4]   2>        5       /solr/autoscaling/events/.auto_add_replicas
   [junit4]   2>        5       /solr/overseer/queue
   [junit4]   2>        5       /solr/overseer/collection-queue-work
   [junit4]   2>        2       /solr/autoscaling/events/node_lost_triggerMR
   [junit4]   2>        2       /solr/autoscaling/events/node_added_triggerCTOOR
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_886A180CCD571763-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{_version_=PostingsFormat(name=Asserting), 
id=PostingsFormat(name=LuceneFixedGap), x_s=PostingsFormat(name=Asserting)}, 
docValues:{}, maxPointsInLeafNode=1159, maxMBSortInHeap=5.6192318116564435, 
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@16b0951),
 locale=bg-BG, timezone=America/Shiprock
   [junit4]   2> NOTE: Linux 4.13.0-32-generic i386/Oracle Corporation 
1.8.0_162 (32-bit)/cpus=8,threads=1,free=250228872,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [ExecutePlanActionTest, 
SolrCloudExampleTest, TestCloudDeleteByQuery, TestAtomicUpdateErrorCases, 
DeleteReplicaTest, UUIDUpdateProcessorFallbackTest, 
TestPullReplicaErrorHandling, CoreMergeIndexesAdminHandlerTest, BJQParserTest, 
ZkShardTermsTest, TestUninvertingReader, TestRandomDVFaceting, 
LeaderElectionIntegrationTest, TestRealTimeGet, DistributedDebugComponentTest, 
CachingDirectoryFactoryTest, TestDistribIDF, TestCoreContainer, MultiTermTest, 
TestSolrCLIRunExample, AutoscalingHistoryHandlerTest, 
TestDeleteCollectionOnDownNodes, HdfsBasicDistributedZkTest, SpatialFilterTest, 
TestFieldCache, SortSpecParsingTest, SchemaApiFailureTest, UpdateLogTest, 
AliasIntegrationTest, RestartWhileUpdatingTest, CopyFieldTest, 
SpellCheckCollatorWithCollapseTest, TestConfigSetImmutable, 
TestReplicaProperties, TestCloudPivotFacet, ShowFileRequestHandlerTest, 
TestTolerantSearch, BasicDistributedZk2Test, ResponseLogComponentTest, 
SmileWriterTest, ConnectionManagerTest, TestFileDictionaryLookup, 
TestClassicSimilarityFactory, TestBadConfig, CircularListTest, TestUtils, 
TestDistribStateManager, TestPayloadScoreQParserPlugin, 
AnalysisAfterCoreReloadTest, TestStressReorder, StatsReloadRaceTest, 
DocValuesMultiTest, TestImpersonationWithHadoopAuth, TestNumericRangeQuery64, 
DistributedFacetSimpleRefinementLongTailTest, FileBasedSpellCheckerTest, 
RegexBoostProcessorTest, TestFastWriter, SolrCmdDistributorTest, 
ReplaceNodeNoTargetTest, TestNamedUpdateProcessors, CurrencyFieldTypeTest, 
LukeRequestHandlerTest, MetricTriggerTest, EnumFieldTest, 
PingRequestHandlerTest, TestJsonRequest, TriLevelCompositeIdRoutingTest, 
DistributedSpellCheckComponentTest, TestUseDocValuesAsStored, 
CollectionTooManyReplicasTest, TestJavabinTupleStreamParser, 
SpatialHeatmapFacetsTest, URLClassifyProcessorTest, TestCodecSupport, 
ShardSplitTest, TestDynamicFieldCollectionResource, 
DistributedFacetPivotSmallTest, MultiThreadedOCPTest, 
TestExclusionRuleCollectionAccess, TestConfigsApi, DistribCursorPagingTest, 
TestDistributedMissingSort, ConvertedLegacyTest, 
HdfsTlogReplayBufferedWhileIndexingTest, HdfsNNFailoverTest, 
UnloadDistributedZkTest, StressHdfsTest, TestPolicyCloud, ConnectionReuseTest, 
SolrShardReporterTest, DistributedQueueTest, TestSchemaManager, 
TestManagedStopFilterFactory, DirectSolrSpellCheckerTest, TestMacroExpander, 
NoCacheHeaderTest, ZkStateWriterTest, TestLegacyField, 
PreAnalyzedUpdateProcessorTest, TestSubQueryTransformerDistrib, 
ClassificationUpdateProcessorIntegrationTest, NotRequiredUniqueKeyTest, 
TestTrieFacet, OverseerRolesTest, MetricUtilsTest, TestNRTOpen, 
TestReloadDeadlock, TestSystemCollAutoCreate, SolrJmxReporterTest, 
SearchHandlerTest, TestFaceting, SolrTestCaseJ4Test, InfixSuggestersTest, 
TestValueSourceCache, TestCorePropertiesReload, TestLazyCores, 
HttpPartitionTest, TestOnReconnectListenerSupport, TestNestedDocsSort, 
TestTolerantUpdateProcessorRandomCloud, TestRebalanceLeaders, 
TestMinMaxOnMultiValuedField, TestLargeCluster, DirectoryFactoryTest, 
JvmMetricsTest, TestJmxIntegration, TestCSVResponseWriter, QueryParsingTest, 
TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, 
TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, 
TestComponentsName, SearchHandlerTest, TestLFUCache, PreAnalyzedFieldTest, 
TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, 
DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, 
RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, SliceStateTest, 
SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, 
DistributedMLTComponentTest, DistributedIntervalFacetingTest, 
TestCrossCoreJoin, TestHighlightDedupGrouping, TestSimpleTrackingShardHandler, 
TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, 
ActionThrottleTest, AddReplicaTest, AssignBackwardCompatibilityTest, 
CleanupOldIndexTest, CloudExitableDirectoryReaderTest, CollectionsAPISolrJTest, 
DeleteNodeTest, DocValuesNotIndexedTest, HealthCheckHandlerTest, 
HttpPartitionOnCommitTest, LIRRollingUpdatesTest, 
LeaderFailoverAfterPartitionTest, LeaderInitiatedRecoveryOnShardRestartTest, 
LegacyCloudClusterPropTest, MoveReplicaHDFSTest, 
OverriddenZkACLAndCredentialsProvidersTest, RemoteQueryErrorTest, 
RollingRestartTest, SaslZkACLProviderTest, SolrCLIZkUtilsTest, 
TestCloudInspectUtil, TestCloudPseudoReturnFields, TestCloudRecovery, 
TestConfigSetsAPI, TestCryptoKeys, TestLeaderElectionZkExpiry, 
TestMiniSolrCloudClusterSSL, TestRandomFlRTGCloud, 
CollectionsAPIAsyncDistributedZkTest, TestCollectionsAPIViaSolrCloudCluster, 
TestLocalFSCloudBackupRestore, AutoAddReplicasIntegrationTest, 
TriggerIntegrationTest]
   [junit4] Completed [633/775 (1!)] on J2 in 183.71s, 14 tests, 2 failures <<< 
FAILURES!

[...truncated 44362 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to