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

1 tests failed.
FAILED:  
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeAddedTrigger

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([461A139E1CB37D2:220B1F00FAC498BE]: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.testNodeAddedTrigger(TriggerIntegrationTest.java:456)
        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 14163 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_461A139E1CB37D2-001/init-core-data-001
   [junit4]   2> 3165448 WARN  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
   [junit4]   2> 3165448 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 3165450 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 3165450 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 3165451 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-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_461A139E1CB37D2-001/tempDir-001
   [junit4]   2> 3165451 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3165451 INFO  (Thread-5491) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3165451 INFO  (Thread-5491) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3165453 ERROR (Thread-5491) [    ] 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> 3165551 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:38931
   [junit4]   2> 3165554 INFO  (zkConnectionManagerCallback-8651-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165558 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3165558 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3165559 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@10ce515{/solr,null,AVAILABLE}
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1799791{/solr,null,AVAILABLE}
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@6c289a{HTTP/1.1,[http/1.1]}{127.0.0.1:42087}
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.e.j.s.Server Started @3167070ms
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=42087}
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@11f642e{HTTP/1.1,[http/1.1]}{127.0.0.1:44619}
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.e.j.s.Server Started @3167070ms
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=44619}
   [junit4]   2> 3165560 ERROR (jetty-launcher-8648-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3165560 ERROR (jetty-launcher-8648-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3165560 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3165561 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:42.581Z
   [junit4]   2> 3165561 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:42.581Z
   [junit4]   2> 3165562 INFO  (zkConnectionManagerCallback-8655-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165562 INFO  (zkConnectionManagerCallback-8654-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165562 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3165562 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3165580 INFO  (jetty-launcher-8648-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3165580 INFO  (jetty-launcher-8648-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3165581 INFO  (zkConnectionManagerCallback-8660-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165581 INFO  (zkConnectionManagerCallback-8663-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165586 INFO  
(zkConnectionManagerCallback-8665-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165586 INFO  
(zkConnectionManagerCallback-8667-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165620 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3165620 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3165621 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:42087_solr
   [junit4]   2> 3165621 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:44619_solr
   [junit4]   2> 3165621 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.Overseer Overseer 
(id=72120154894172165-127.0.0.1:42087_solr-n_0000000000) starting
   [junit4]   2> 3165623 INFO  
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3165624 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3165627 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 3165627 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42087_solr
   [junit4]   2> 3165628 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 3165628 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:44619_solr]
   [junit4]   2> 3165629 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 3165629 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 3165629 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3165630 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3165630 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3165630 DEBUG (ScheduledTrigger-9434-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 1
   [junit4]   2> 3165630 INFO  
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3165749 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44619.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165752 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42087.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165755 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44619.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165755 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44619.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165756 INFO  (jetty-launcher-8648-thread-2) 
[n:127.0.0.1:44619_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_461A139E1CB37D2-001/tempDir-001/node2/.
   [junit4]   2> 3165760 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42087.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165761 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_42087.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3165762 INFO  (jetty-launcher-8648-thread-1) 
[n:127.0.0.1:42087_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_461A139E1CB37D2-001/tempDir-001/node1/.
   [junit4]   2> 3165785 INFO  (zkConnectionManagerCallback-8673-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165788 INFO  (zkConnectionManagerCallback-8677-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165789 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3165789 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38931/solr ready
   [junit4]   2> 3165842 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
   [junit4]   2> 3165843 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
   [junit4]   2> 3165843 DEBUG 
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 2
   [junit4]   2> 3165843 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 2
   [junit4]   2> 3165844 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3165845 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3165845 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 3165847 INFO  (qtp16175053-32730) [n:127.0.0.1:42087_solr    ] 
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with 
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 3165850 INFO  (qtp16175053-32730) [n:127.0.0.1:42087_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=2
   [junit4]   2> 3165851 INFO  (qtp16175053-32792) [n:127.0.0.1:42087_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> 3165852 INFO  (qtp32814196-32733) [n:127.0.0.1:44619_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> 3165853 DEBUG (qtp16175053-32738) [n:127.0.0.1:42087_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3165853 INFO  (qtp16175053-32738) [n:127.0.0.1:42087_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 3165853 DEBUG 
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 3
   [junit4]   2> 3165854 INFO  
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestEventQueueAction instantiated
   [junit4]   2> 3165856 DEBUG 
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:42087_solr, 127.0.0.1:44619_solr]
   [junit4]   2> 3165856 DEBUG 
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_triggerEQ instantiated with properties: {event=nodeAdded, waitFor=1, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
 enabled=true}
   [junit4]   2> 3165856 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 3
   [junit4]   2> 3165856 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3165857 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3165857 DEBUG (ScheduledTrigger-9434-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_triggerEQ
   [junit4]   2> 3165858 DEBUG (ScheduledTrigger-9434-thread-1) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3165858 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3165858 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 3165864 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3165864 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3165864 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 3165865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@1f6ddcf{/solr,null,AVAILABLE}
   [junit4]   2> 3165865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@9b6383{HTTP/1.1,[http/1.1]}{127.0.0.1:44729}
   [junit4]   2> 3165865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server Started @3167375ms
   [junit4]   2> 3165865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=44729}
   [junit4]   2> 3165865 ERROR 
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3165866 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3165866 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3165866 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3165866 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:42.886Z
   [junit4]   2> 3165882 INFO  (zkConnectionManagerCallback-8679-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165883 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3165890 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3165891 INFO  (zkConnectionManagerCallback-8683-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165895 INFO  
(zkConnectionManagerCallback-8685-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3165899 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3165900 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3165902 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:44729_solr
   [junit4]   2> 3165902 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3165903 INFO  
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3165911 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3165915 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3166041 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44729.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3166053 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44729.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3166053 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_44729.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3166059 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:44729_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_461A139E1CB37D2-001/tempDir-001/node3/.
   [junit4]   2> 3166860 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_triggerEQ
   [junit4]   2> 3166860 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3166860 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:44729_solr at time 954604317937148
   [junit4]   2> 3167849 INFO  
(OverseerCollectionConfigSetProcessor-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.OverseerTaskQueue Response ZK path: 
/overseer/collection-queue-work/qnr-0000000000 doesn't exist.  Requestor may 
have disconnected from ZooKeeper
   [junit4]   2> 3167861 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_triggerEQ
   [junit4]   2> 3167861 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3167861 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_triggerEQ firing registered processor for nodes: 
[127.0.0.1:44729_solr] added at times [954604317937148], now=954605318664328
   [junit4]   2> 3167861 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"]}}
   [junit4]   2> 3167862 DEBUG (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_triggerEQ]
   [junit4]   2> 3167862 INFO  (ScheduledTrigger-9434-thread-2) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3167862 DEBUG 
(AutoscalingActionExecutor-9435-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "_enqueue_time_":954605319793943,
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"]}}
   [junit4]   2> 3167863 INFO  
(AutoscalingActionExecutor-9435-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.TriggerIntegrationTest -- event: {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "_enqueue_time_":954605319793943,
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"]}}
   [junit4]   2> 3167863 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@6c289a{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 3167864 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=26233821
   [junit4]   2> 3167865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 3167865 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@73e518: rootName = 
solr_42087, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@20460
   [junit4]   2> 3167875 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 3167875 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@1e0ce8b: rootName = 
solr_42087, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@19e515
   [junit4]   2> 3167881 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 3167881 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@9a844: rootName = 
solr_42087, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@3836af
   [junit4]   2> 3167882 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:42087_solr
   [junit4]   2> 3167883 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 3167883 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 3167883 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3167883 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 3167883 INFO  
(zkCallback-8664-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3167883 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 3167883 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.Overseer Overseer 
(id=72120154894172165-127.0.0.1:42087_solr-n_0000000000) closing
   [junit4]   2> 3167883 INFO  
(OverseerStateUpdate-72120154894172165-127.0.0.1:42087_solr-n_0000000000) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:42087_solr
   [junit4]   2> 3167883 WARN  
(OverseerAutoScalingTriggerThread-72120154894172165-127.0.0.1:42087_solr-n_0000000000)
 [n:127.0.0.1:42087_solr    ] o.a.s.c.a.OverseerTriggerThread 
OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 3167883 DEBUG 
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 3167883 WARN  
(AutoscalingActionExecutor-9435-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.ScheduledTriggers Exception executing 
actions
   [junit4]   2> org.apache.lucene.store.AlreadyClosedException: 
ScheduledTrigger node_added_triggerEQ has been closed.
   [junit4]   2>        at 
org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.dequeue(ScheduledTriggers.java:525)
   [junit4]   2>        at 
org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:309)
   [junit4]   2>        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2>        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 3167893 DEBUG 
(AutoscalingActionExecutor-9435-thread-1-processing-n:127.0.0.1:42087_solr) 
[n:127.0.0.1:42087_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 30 
ms for event id=3643523458dfcTf012tcuibqfqvrtj1khnkfy62
   [junit4]   2> 3167893 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 
0x10038e6159d0005, likely client has closed socket
   [junit4]   2> 3167894 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@10ce515{/solr,null,UNAVAILABLE}
   [junit4]   2> 3167895 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3167895 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:44619_solr
   [junit4]   2> 3167895 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.Overseer Overseer 
(id=72120154894172166-127.0.0.1:44619_solr-n_0000000001) starting
   [junit4]   2> 3167897 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 4
   [junit4]   2> 3167898 INFO  
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestEventQueueAction instantiated
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:44729_solr, 127.0.0.1:44619_solr]
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_triggerEQ instantiated with properties: {event=nodeAdded, waitFor=1, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
 enabled=true}
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:44729_solr, 127.0.0.1:44619_solr]
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion -1
   [junit4]   2> 3167898 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 4
   [junit4]   2> 3167899 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3167900 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 2
   [junit4]   2> 3167900 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 3167900 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "_dequeue_time_":954605357803221,
   [junit4]   2>     "_enqueue_time_":954605319793943,
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 3167901 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[.auto_add_replicas, node_added_triggerEQ]
   [junit4]   2> 3167901 INFO  (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3167901 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "_dequeue_time_":954605357803221,
   [junit4]   2>     "_enqueue_time_":954605319793943,
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 3167901 INFO  
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.TriggerIntegrationTest -- event: {
   [junit4]   2>   "id":"3643523458dfcTf012tcuibqfqvrtj1khnkfy62",
   [junit4]   2>   "source":"node_added_triggerEQ",
   [junit4]   2>   "eventTime":954604317937148,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954604317937148],
   [junit4]   2>     "_dequeue_time_":954605357803221,
   [junit4]   2>     "_enqueue_time_":954605319793943,
   [junit4]   2>     "nodeNames":["127.0.0.1:44729_solr"],
   [junit4]   2>     "replaying":true}}
   [junit4]   2> 3167902 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_triggerEQ
   [junit4]   2> 3167902 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3167902 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
.auto_add_replicas after 5000ms
   [junit4]   2> 3167903 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_triggerEQ after 5000ms
   [junit4]   2> 3167903 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=3643523458dfcTf012tcuibqfqvrtj1khnkfy62
   [junit4]   2> 3172895 INFO  
(TEST-TriggerIntegrationTest.testEventQueue-seed#[461A139E1CB37D2]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
   [junit4]   2> 3172903 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 2
   [junit4]   2> 3172905 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_triggerEQ
   [junit4]   2> 3172905 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3172945 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testCooldown
   [junit4]   2> 3172945 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
   [junit4]   2> 3172946 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 5
   [junit4]   2> 3172946 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 5
   [junit4]   2> 3172947 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3172947 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3172948 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 3172950 INFO  (qtp32814196-32835) [n:127.0.0.1:44619_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> 3172951 INFO  (qtp4451349-32797) [n:127.0.0.1:44729_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> 3172951 DEBUG (qtp32814196-32745) [n:127.0.0.1:44619_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3172951 INFO  (qtp32814196-32745) [n:127.0.0.1:44619_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=2
   [junit4]   2> 3172951 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 6
   [junit4]   2> 3172952 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:44729_solr, 127.0.0.1:44619_solr]
   [junit4]   2> 3172952 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, 
waitFor=1, actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3172952 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 6
   [junit4]   2> 3172953 INFO  
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3172955 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3172955 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 3172955 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3172955 INFO  (qtp32814196-32733) [n:127.0.0.1:44619_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> 3172955 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3172956 INFO  (qtp4451349-32802) [n:127.0.0.1:44729_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> 3172956 DEBUG (qtp32814196-32743) [n:127.0.0.1:44619_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3172956 INFO  (qtp32814196-32743) [n:127.0.0.1:44619_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 3172956 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 7
   [junit4]   2> 3172956 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:44729_solr, 127.0.0.1:44619_solr]
   [junit4]   2> 3172956 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, 
waitFor=1, actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3172956 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 7
   [junit4]   2> 3172957 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3172957 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3172957 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@a5a231{/solr,null,AVAILABLE}
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@e40db9{HTTP/1.1,[http/1.1]}{127.0.0.1:32843}
   [junit4]   2> 3172963 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server Started @3174473ms
   [junit4]   2> 3172964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=32843}
   [junit4]   2> 3172964 ERROR 
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3172964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3172964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3172964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3172964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:49.984Z
   [junit4]   2> 3172970 INFO  (zkConnectionManagerCallback-8689-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3172970 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3172978 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3172982 INFO  (zkConnectionManagerCallback-8693-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3172986 INFO  
(zkConnectionManagerCallback-8695-thread-1-processing-n:127.0.0.1:32843_solr) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3172988 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3172989 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3172990 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:32843_solr
   [junit4]   2> 3172990 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3172990 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3172991 INFO  
(zkCallback-8694-thread-1-processing-n:127.0.0.1:32843_solr) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3172991 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3173076 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_32843.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3173084 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_32843.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3173084 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_32843.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3173085 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:32843_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_461A139E1CB37D2-001/tempDir-001/node4/.
   [junit4]   2> 3173955 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3173955 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3173956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:32843_solr at time 954611413476825
   [junit4]   2> 3174956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3174956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3174956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger firing registered processor for nodes: 
[127.0.0.1:32843_solr] added at times [954611413476825], now=954612414284576
   [junit4]   2> 3174956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"36436ca32e5d9Tf012tcuibqfqvrtj1khnkfy65",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954611413476825,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954611413476825],
   [junit4]   2>     "nodeNames":["127.0.0.1:32843_solr"]}}
   [junit4]   2> 3174956 DEBUG (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_cooldown_trigger]
   [junit4]   2> 3174957 INFO  (ScheduledTrigger-9449-thread-4) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3174957 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"36436ca32e5d9Tf012tcuibqfqvrtj1khnkfy65",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954611413476825,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954611413476825],
   [junit4]   2>     "_enqueue_time_":954612414498491,
   [junit4]   2>     "nodeNames":["127.0.0.1:32843_solr"]}}
   [junit4]   2> 3174958 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_cooldown_trigger after 5000ms
   [junit4]   2> 3174958 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=36436ca32e5d9Tf012tcuibqfqvrtj1khnkfy65
   [junit4]   2> 3175958 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3175959 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3175959 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3175959 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3175959 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@f71072{/solr,null,AVAILABLE}
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@1c22769{HTTP/1.1,[http/1.1]}{127.0.0.1:36423}
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server Started @3177470ms
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=36423}
   [junit4]   2> 3175960 ERROR 
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3175960 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:52.980Z
   [junit4]   2> 3175963 INFO  (zkConnectionManagerCallback-8699-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3175964 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3175972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3175973 INFO  (zkConnectionManagerCallback-8703-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3175976 INFO  
(zkConnectionManagerCallback-8705-thread-1-processing-n:127.0.0.1:36423_solr) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3175980 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3175981 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3175981 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:36423_solr
   [junit4]   2> 3175982 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3175982 INFO  
(zkCallback-8694-thread-1-processing-n:127.0.0.1:32843_solr) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3175982 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3175982 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3175987 INFO  
(zkCallback-8704-thread-1-processing-n:127.0.0.1:36423_solr) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3176054 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36423.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3176062 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36423.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3176062 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_36423.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3176064 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:36423_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_461A139E1CB37D2-001/tempDir-001/node5/.
   [junit4]   2> 3179960 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3179960 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3179960 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:36423_solr at time 954617418380624
   [junit4]   2> 3180961 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3180961 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3180961 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger firing registered processor for nodes: 
[127.0.0.1:36423_solr] added at times [954617418380624], now=954618419115718
   [junit4]   2> 3180961 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"36438301e7550Tf012tcuibqfqvrtj1khnkfy67",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954617418380624,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954617418380624],
   [junit4]   2>     "nodeNames":["127.0.0.1:36423_solr"]}}
   [junit4]   2> 3180961 DEBUG (ScheduledTrigger-9449-thread-3) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_cooldown_trigger]
   [junit4]   2> 3180962 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"36438301e7550Tf012tcuibqfqvrtj1khnkfy67",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954617418380624,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954617418380624],
   [junit4]   2>     "_enqueue_time_":954618419350162,
   [junit4]   2>     "nodeNames":["127.0.0.1:36423_solr"]}}
   [junit4]   2> 3180962 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_cooldown_trigger after 5000ms
   [junit4]   2> 3180962 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 0 
ms for event id=36438301e7550Tf012tcuibqfqvrtj1khnkfy67
   [junit4]   2> 3182965 INFO  (qtp13189800-32889) [n:127.0.0.1:32843_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> 3182966 INFO  (qtp9239947-32864) [n:127.0.0.1:36423_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> 3182966 INFO  (qtp32814196-32743) [n:127.0.0.1:44619_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> 3182967 INFO  (qtp4451349-32803) [n:127.0.0.1:44729_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> 3182967 DEBUG (qtp13189800-32840) [n:127.0.0.1:32843_solr    ] 
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3182968 INFO  (qtp13189800-32840) [n:127.0.0.1:32843_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=4
   [junit4]   2> 3182968 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 8
   [junit4]   2> 3182968 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:32843_solr, 127.0.0.1:44729_solr, 127.0.0.1:36423_solr, 
127.0.0.1:44619_solr]
   [junit4]   2> 3182968 DEBUG 
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger instantiated with properties: {event=nodeAdded, 
waitFor=1, actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3182968 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 8
   [junit4]   2> 3182968 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Changing value of 
autoscaling property: triggerCooldownPeriodSeconds from: 5 to: 7
   [junit4]   2> 3182968 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3182969 DEBUG 
(OverseerAutoScalingTriggerThread-72120154894172166-127.0.0.1:44619_solr-n_0000000001)
 [n:127.0.0.1:44619_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 8, lastZnodeVersion 8
   [junit4]   2> 3182969 INFO  (qtp9239947-32870) [n:127.0.0.1:36423_solr    ] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 3182970 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3182971 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3182971 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3182971 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3182971 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@12551f3{/solr,null,AVAILABLE}
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@10b6aa2{HTTP/1.1,[http/1.1]}{127.0.0.1:43965}
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server Started @3184482ms
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=43965}
   [junit4]   2> 3182972 ERROR 
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3182972 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:50:59.992Z
   [junit4]   2> 3182974 INFO  (zkConnectionManagerCallback-8709-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3182974 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3182981 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3182982 INFO  (zkConnectionManagerCallback-8713-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3182983 INFO  
(zkConnectionManagerCallback-8715-thread-1-processing-n:127.0.0.1:43965_solr) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3182985 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (4)
   [junit4]   2> 3182986 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3182986 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:43965_solr
   [junit4]   2> 3182987 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3182987 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3182987 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
   [junit4]   2> 3182987 INFO  
(zkCallback-8694-thread-1-processing-n:127.0.0.1:32843_solr) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3182987 INFO  
(zkCallback-8704-thread-1-processing-n:127.0.0.1:36423_solr) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3182988 INFO  
(zkCallback-8714-thread-1-processing-n:127.0.0.1:43965_solr) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (5)
   [junit4]   2> 3183065 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43965.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3183073 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43965.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3183073 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_43965.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3183074 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:43965_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_461A139E1CB37D2-001/tempDir-001/node6/.
   [junit4]   2> 3185962 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3185963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5
   [junit4]   2> 3185963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:43965_solr at time 954623420592922
   [junit4]   2> 3186963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3186963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5
   [junit4]   2> 3186963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger firing registered processor for nodes: 
[127.0.0.1:43965_solr] added at times [954623420592922], now=954624421322097
   [junit4]   2> 3186963 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"3643995e0f31aTf012tcuibqfqvrtj1khnkfy68",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954623420592922,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954623420592922],
   [junit4]   2>     "nodeNames":["127.0.0.1:43965_solr"]}}
   [junit4]   2> 3186964 DEBUG (ScheduledTrigger-9449-thread-2) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_cooldown_trigger]
   [junit4]   2> 3186964 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"3643995e0f31aTf012tcuibqfqvrtj1khnkfy68",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954623420592922,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954623420592922],
   [junit4]   2>     "_enqueue_time_":954624421580445,
   [junit4]   2>     "nodeNames":["127.0.0.1:43965_solr"]}}
   [junit4]   2> 3186965 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Resuming trigger: 
node_added_cooldown_trigger after 7000ms
   [junit4]   2> 3186965 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 0 
ms for event id=3643995e0f31aTf012tcuibqfqvrtj1khnkfy68
   [junit4]   2> 3186965 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-22T00:27:37+03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 3186966 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.session Scavenging every 600000ms
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@3e42e8{/solr,null,AVAILABLE}
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@19912d9{HTTP/1.1,[http/1.1]}{127.0.0.1:46639}
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.e.j.s.Server Started @3188477ms
   [junit4]   2> 3186967 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=46639}
   [junit4]   2> 3186968 ERROR 
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3186968 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
8.0.0
   [junit4]   2> 3186968 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3186968 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3186968 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-09T15:51:03.988Z
   [junit4]   2> 3186969 INFO  (zkConnectionManagerCallback-8719-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3186969 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3186976 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38931/solr
   [junit4]   2> 3186977 INFO  (zkConnectionManagerCallback-8723-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3186979 INFO  
(zkConnectionManagerCallback-8725-thread-1-processing-n:127.0.0.1:46639_solr) 
[n:127.0.0.1:46639_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3186982 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (5)
   [junit4]   2> 3186982 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3186983 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:46639_solr
   [junit4]   2> 3186984 INFO  
(zkCallback-8704-thread-1-processing-n:127.0.0.1:36423_solr) 
[n:127.0.0.1:36423_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3186984 INFO  
(zkCallback-8714-thread-1-processing-n:127.0.0.1:43965_solr) 
[n:127.0.0.1:43965_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3186984 INFO  
(zkCallback-8684-thread-1-processing-n:127.0.0.1:44729_solr) 
[n:127.0.0.1:44729_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3186984 INFO  
(zkCallback-8666-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3186984 INFO  (zkCallback-8676-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (6)
   [junit4]   2> 3186984 INFO  
(zkCallback-8694-thread-1-processing-n:127.0.0.1:32843_solr) 
[n:127.0.0.1:32843_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3186985 INFO  
(zkCallback-8724-thread-1-processing-n:127.0.0.1:46639_solr) 
[n:127.0.0.1:46639_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (5) -> (6)
   [junit4]   2> 3187077 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46639.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3187085 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46639.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3187085 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_46639.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@22981f
   [junit4]   2> 3187086 INFO  
(TEST-TriggerIntegrationTest.testCooldown-seed#[461A139E1CB37D2]) 
[n:127.0.0.1:46639_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_461A139E1CB37D2-001/tempDir-001/node7/.
   [junit4]   2> 3193965 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3193965 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6
   [junit4]   2> 3193965 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:46639_solr at time 954631423014246
   [junit4]   2> 3194966 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_cooldown_trigger
   [junit4]   2> 3194966 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 6
   [junit4]   2> 3194966 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_cooldown_trigger firing registered processor for nodes: 
[127.0.0.1:46639_solr] added at times [954631423014246], now=954632423632776
   [junit4]   2> 3194966 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"3643b72dc3566Tf012tcuibqfqvrtj1khnkfy69",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954631423014246,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954631423014246],
   [junit4]   2>     "nodeNames":["127.0.0.1:46639_solr"]}}
   [junit4]   2> 3194966 DEBUG (ScheduledTrigger-9449-thread-1) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: 
[node_added_cooldown_trigger]
   [junit4]   2> 3194966 DEBUG 
(AutoscalingActionExecutor-9450-thread-1-processing-n:127.0.0.1:44619_solr) 
[n:127.0.0.1:44619_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"3643b72dc3566Tf012tcuibqfqvrtj1khnkfy69",
   [junit4]   2>   "source":"node_added_cooldown_trigger",
   [junit4]   2>   "eventTime":954631423014246,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[954631423014246],
   [junit4]   2>     "_enqueue_time_":954632423839967,
   [junit4]   2>     "nodeNames":["127.0.0.1:46639_solr"]}}
   [juni

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

:1085)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269)
   [junit4]   2>        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]   2>        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]   2>        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2>        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 3381819 INFO  (jetty-closer-8649-thread-11) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3381820 INFO  (jetty-closer-8649-thread-8) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@11377e3{/solr,null,UNAVAILABLE}
   [junit4]   2> 3381821 INFO  (jetty-closer-8649-thread-8) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3381856 INFO  (jetty-closer-8649-thread-6) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@dc42c4{/solr,null,UNAVAILABLE}
   [junit4]   2> 3381857 INFO  (jetty-closer-8649-thread-6) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 3381858 ERROR 
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-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> 3381858 INFO  
(SUITE-TriggerIntegrationTest-seed#[461A139E1CB37D2]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:38931 38931
   [junit4]   2> 3389885 INFO  (Thread-5491) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:38931 38931
   [junit4]   2> 3389887 WARN  (Thread-5491) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        44      /solr/collections/collection1/terms/shard1
   [junit4]   2>        22      /solr/clusterprops.json
   [junit4]   2>        22      /solr/aliases.json
   [junit4]   2>        21      /solr/security.json
   [junit4]   2>        11      /solr/configs/conf
   [junit4]   2>        10      /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>        127     /solr/collections/collection1/state.json
   [junit4]   2>        43      /solr/collections/testMetricTrigger/state.json
   [junit4]   2>        22      /solr/clusterstate.json
   [junit4]   2>        6       /solr/autoscaling.json
   [junit4]   2>        3       
/solr/collections/collection1/leader_elect/shard1/election/72120154894172183-core_node8-n_0000000003
   [junit4]   2>        3       
/solr/overseer_elect/election/72120154894172208-127.0.0.1:41629_solr-n_0000000014
   [junit4]   2>        2       
/solr/overseer_elect/election/72120154894172217-127.0.0.1:46213_solr-n_0000000017
   [junit4]   2>        2       
/solr/overseer_elect/election/72120154894172205-127.0.0.1:46791_solr-n_0000000013
   [junit4]   2>        2       
/solr/overseer_elect/election/72120154894172192-127.0.0.1:37179_solr-n_0000000009
   [junit4]   2>        2       
/solr/collections/collection1/leader_elect/shard1/election/72120154894172196-core_node3-n_0000000000
   [junit4]   2>        2       
/solr/overseer_elect/election/72120154894172186-127.0.0.1:42403_solr-n_0000000007
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        22      /solr/live_nodes
   [junit4]   2>        22      /solr/collections
   [junit4]   2>        6       /solr/overseer/queue-work
   [junit4]   2>        6       /solr/autoscaling/events/.auto_add_replicas
   [junit4]   2>        6       /solr/overseer/queue
   [junit4]   2>        6       /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_461A139E1CB37D2-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{id=BlockTreeOrds(blocksize=128), x_s=PostingsFormat(name=Direct)}, 
docValues:{_version_=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=799, 
maxMBSortInHeap=5.140393441071785, 
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1fa3458),
 locale=sq, timezone=America/Guadeloupe
   [junit4]   2> NOTE: Linux 4.13.0-32-generic i386/Oracle Corporation 
1.8.0_162 (32-bit)/cpus=8,threads=1,free=171753240,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: 
[TestComplexPhraseLeadingWildcard, TestFieldSortValues, OverseerRolesTest, 
SpatialFilterTest, TestChildDocTransformer, TestManagedSchemaAPI, 
RecoveryZkTest, TestUtils, TestFileDictionaryLookup, 
TestMinMaxOnMultiValuedField, TestSimpleTextCodec, TestAtomicUpdateErrorCases, 
SaslZkACLProviderTest, ReplaceNodeNoTargetTest, ExecutePlanActionTest, 
TestLegacyField, SuggesterTSTTest, PropertiesRequestHandlerTest, 
TestNumericRangeQuery64, UninvertDocValuesMergePolicyTest, TestCodecSupport, 
BJQParserTest, CdcrUpdateLogTest, TestDynamicFieldCollectionResource, 
ZkStateWriterTest, DateMathParserTest, HighlighterMaxOffsetTest, 
TestPullReplicaErrorHandling, StatelessScriptUpdateProcessorFactoryTest, 
StatsReloadRaceTest, SearchRateTriggerTest, TestFieldCacheSortRandom, 
DistributedFacetPivotSmallTest, CoreAdminHandlerTest, TestQueryTypes, 
TestSolrCloudWithSecureImpersonation, ConvertedLegacyTest, 
TestCloudSearcherWarming, DistributedFacetPivotLargeTest, 
IndexSchemaRuntimeFieldTest, TestSkipOverseerOperations, TestUpdate, 
LukeRequestHandlerTest, AnalyticsQueryTest, SolrShardReporterTest, 
SpellPossibilityIteratorTest, JvmMetricsTest, TestUninvertingReader, 
HttpPartitionTest, TestSolrCLIRunExample, TestQuerySenderListener, 
DisMaxRequestHandlerTest, TestLargeCluster, TestConfigSetImmutable, 
EnumFieldTest, OverriddenZkACLAndCredentialsProvidersTest, TestBadConfig, 
TestConfigsApi, TestRandomDVFaceting, CopyFieldTest, TestSchemaVersionResource, 
TestExportWriter, RestartWhileUpdatingTest, TestJsonRequest, 
CurrencyFieldTypeTest, ResponseLogComponentTest, CleanupOldIndexTest, 
LeaderElectionTest, TestFaceting, HdfsRestartWhileUpdatingTest, 
TestSchemaManager, TestFiltering, RegexBoostProcessorTest, TestCloudPivotFacet, 
TestImplicitCoreProperties, TestCloudDeleteByQuery, TestDistributedMissingSort, 
TestStressReorder, MoveReplicaHDFSFailoverTest, SearchHandlerTest, 
SchemaApiFailureTest, TestTrieFacet, CacheHeaderTest, 
LegacyCloudClusterPropTest, TermVectorComponentTest, TestRangeQuery, 
SpellCheckCollatorWithCollapseTest, TestCorePropertiesReload, 
DistributedDebugComponentTest, TestCoreBackup, 
AtomicUpdateProcessorFactoryTest, URLClassifyProcessorTest, TestSegmentSorting, 
CollectionsAPISolrJTest, AutoAddReplicasPlanActionTest, 
CdcrReplicationDistributedZkTest, TestManagedStopFilterFactory, 
TestSolrCoreProperties, PreAnalyzedFieldTest, TestPolicyCloud, 
FileBasedSpellCheckerTest, TestImpersonationWithHadoopAuth, LargeFieldTest, 
AnalysisAfterCoreReloadTest, TestTolerantUpdateProcessorRandomCloud, 
TestSystemCollAutoCreate, TestLazyCores, SolrCloudExampleTest, 
CachingDirectoryFactoryTest, TestNestedDocsSort, 
DocExpirationUpdateProcessorFactoryTest, ReturnFieldsTest, 
DistribCursorPagingTest, TestMaxScoreQueryParser, DocValuesTest, 
BasicDistributedZk2Test, TestLeaderInitiatedRecoveryThread, 
DistributedQueryComponentOptimizationTest, DistributedQueueTest, 
ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestReloadDeadlock, 
TestPayloadScoreQParserPlugin, ShardSplitTest, TestHashQParserPlugin, 
TestReqParamsAPI, SOLR749Test, AlternateDirectoryTest, TestSolrIndexConfig, 
TestQuerySenderNoQuery, TestStressRecovery, TestMergePolicyConfig, 
TestSolrDeletionPolicy2, MultiTermTest, TestDocSet, NumericFieldsTest, 
MinimalSchemaTest, TestElisionMultitermQuery, ExternalFileFieldSortTest, 
TestPostingsSolrHighlighter, DirectSolrConnectionTest, 
NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPhraseSuggestions, 
TestCharFilters, TestDFRSimilarityFactory, TestPerFieldSimilarity, 
TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, 
TestBM25SimilarityFactory, TestFastWriter, TimeZoneUtilsTest, 
ResourceLoaderTest, ScriptEngineTest, PrimUtilsTest, 
TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, 
ClusterStateTest, SliceStateTest, UUIDFieldTest, CircularListTest, 
DistributedIntervalFacetingTest, SolrTestCaseJ4Test, TestCrossCoreJoin, 
TestSimpleTrackingShardHandler, TestTolerantSearch, 
TestEmbeddedSolrServerConstructors, ConnectionReuseTest, 
AssignBackwardCompatibilityTest, AsyncCallRequestStatusResponseTest, 
ChaosMonkeySafeLeaderWithPullReplicasTest, ConfigSetsAPITest, 
DeleteInactiveReplicaTest, DeleteReplicaTest, DeleteStatusTest, 
DocValuesNotIndexedTest, ForceLeaderTest, MoveReplicaTest, 
OutOfBoxZkACLAndCredentialsProvidersTest, 
OverseerCollectionConfigSetProcessorTest, OverseerTaskQueueTest, 
PeerSyncReplicationTest, RemoteQueryErrorTest, ReplicationFactorTest, 
SSLMigrationTest, TestAuthenticationFramework, TestCloudRecovery, 
TestConfigSetsAPIExclusivity, TestConfigSetsAPIZkFailure, TestCryptoKeys, 
TestExclusionRuleCollectionAccess, TestLockTree, TestMiniSolrCloudClusterSSL, 
TestRebalanceLeaders, TestSizeLimitedDistributedMap, TestStressLiveNodes, 
TestUtilizeNode, TriLevelCompositeIdRoutingTest, 
VMParamsZkACLAndCredentialsProvidersTest, ZkShardTermsTest, AssignTest, 
CollectionTooManyReplicasTest, ConcurrentDeleteAndCreateCollectionTest, 
HdfsCollectionsAPIDistributedZkTest, SimpleCollectionCreateDeleteTest, 
TestCollectionsAPIViaSolrCloudCluster, TestReplicaProperties, 
TestRequestStatusCollectionAPI, MetricTriggerTest, SystemLogListenerTest, 
TriggerIntegrationTest]
   [junit4] Completed [604/775 (1!)] on J2 in 224.53s, 14 tests, 1 failure <<< 
FAILURES!

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

Reply via email to