[JENKINS] Lucene-Solr-7.x-Solaris (64bit/jdk1.8.0) - Build # 356 - Still Unstable!

[Policeman Jenkins Server]

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Solaris/356/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC

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

Error Message:


Stack Trace:
java.lang.AssertionError
        at 
__randomizedtesting.SeedInfo.seed([98C4F0A068D35A9F:F3A027E9DBFECF1B]: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.testSetProperties(TriggerIntegrationTest.java:1361)
        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 13580 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
   [junit4]   2> 3946154 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/init-core-data-001
   [junit4]   2> 3946154 WARN  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
   [junit4]   2> 3946154 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 3946156 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
   [junit4]   2> 3946156 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001
   [junit4]   2> 3946156 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 3946156 INFO  (Thread-8437) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3946156 INFO  (Thread-8437) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 3946159 ERROR (Thread-8437) [    ] 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> 3946256 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:34588
   [junit4]   2> 3946266 INFO  (zkConnectionManagerCallback-4767-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946288 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 3946288 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 3946295 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@5f0500d3{/solr,null,AVAILABLE}
   [junit4]   2> 3946295 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@4036f898{/solr,null,AVAILABLE}
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4785b8ba{HTTP/1.1,[http/1.1]}{127.0.0.1:54064}
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.e.j.s.Server Started @3950789ms
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=54064}
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@37d291f6{HTTP/1.1,[http/1.1]}{127.0.0.1:58429}
   [junit4]   2> 3946296 ERROR (jetty-launcher-4764-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.e.j.s.Server Started @3950790ms
   [junit4]   2> 3946296 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3946297 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=58429}
   [junit4]   2> 3946297 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3946297 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3946297 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-27T19:39:33.431Z
   [junit4]   2> 3946297 ERROR (jetty-launcher-4764-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3946297 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3946298 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 3946298 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3946298 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-27T19:39:33.432Z
   [junit4]   2> 3946301 INFO  (zkConnectionManagerCallback-4769-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946301 INFO  (zkConnectionManagerCallback-4771-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946302 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3946303 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3946316 INFO  (jetty-launcher-4764-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
   [junit4]   2> 3946316 INFO  (jetty-launcher-4764-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
   [junit4]   2> 3946318 INFO  (zkConnectionManagerCallback-4777-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946319 INFO  (zkConnectionManagerCallback-4779-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946321 INFO  
(zkConnectionManagerCallback-4781-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946322 INFO  
(zkConnectionManagerCallback-4783-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946462 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3946463 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3946463 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:58429_solr
   [junit4]   2> 3946464 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:54064_solr
   [junit4]   2> 3946465 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.Overseer Overseer 
(id=99247952579198981-127.0.0.1:58429_solr-n_0000000000) starting
   [junit4]   2> 3946468 INFO  
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3946470 INFO  
(zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 3946479 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 3946481 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 3946481 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:54064_solr]
   [junit4]   2> 3946482 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 3946482 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 3946482 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:58429_solr
   [junit4]   2> 3946483 INFO  
(zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3946484 INFO  
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 3946485 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3946485 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 3946486 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: 2
   [junit4]   2> 3946613 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_54064.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946614 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_58429.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946619 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_54064.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946619 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_54064.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946621 INFO  (jetty-launcher-4764-thread-2) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node2/.
   [junit4]   2> 3946622 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_58429.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946622 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_58429.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946623 INFO  (jetty-launcher-4764-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node1/.
   [junit4]   2> 3946653 INFO  (zkConnectionManagerCallback-4789-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946656 INFO  (zkConnectionManagerCallback-4793-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946658 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 3946659 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34588/solr ready
   [junit4]   2> 3946784 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
   [junit4]   2> 3946785 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode 
version 2
   [junit4]   2> 3946786 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 2
   [junit4]   2> 3946786 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 2
   [junit4]   2> 3946791 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3946792 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3946792 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 3946797 INFO  (qtp1937897085-31620) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3946799 INFO  (qtp1298289486-31612) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3946800 DEBUG (qtp1937897085-31617) [n:127.0.0.1:54064_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3946800 INFO  (qtp1937897085-31617) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=4
   [junit4]   2> 3946801 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 3
   [junit4]   2> 3946801 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 3946804 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:58429_solr]
   [junit4]   2> 3946804 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_restore_trigger instantiated with properties: {event=nodeAdded, 
waitFor=5, actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3946804 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 3
   [junit4]   2> 3946805 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@659a3066{/solr,null,AVAILABLE}
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.AbstractConnector Started 
ServerConnector@6d25db28{HTTP/1.1,[http/1.1]}{127.0.0.1:60345}
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.Server Started @3951299ms
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60345}
   [junit4]   2> 3946806 ERROR 
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging 
may be missing or incomplete.
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ 
version 7.3.0
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on 
port null
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3946806 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-27T19:39:33.940Z
   [junit4]   2> 3946807 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3946810 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3946810 INFO  (zkConnectionManagerCallback-4795-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946811 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 3946811 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 3946811 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
   [junit4]   2> 3946811 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3946819 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
   [junit4]   2> 3946821 INFO  (zkConnectionManagerCallback-4799-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946824 INFO  
(zkConnectionManagerCallback-4801-thread-1-processing-n:127.0.0.1:60345_solr) 
[n:127.0.0.1:60345_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3946836 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 3946840 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3946843 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60345_solr
   [junit4]   2> 3946845 INFO  
(zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3946845 INFO  
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3946847 INFO  
(zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) 
[n:127.0.0.1:60345_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 3946847 INFO  (zkCallback-4792-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 3946949 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60345.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946956 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60345.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946956 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60345.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3946957 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [n:127.0.0.1:60345_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node3/.
   [junit4]   2> 3947821 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 3947822 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3947822 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:60345_solr at time 2147034263632547
   [junit4]   2> 3948488 INFO  (qtp1937897085-31622) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948489 INFO  (qtp1298289486-31613) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948492 INFO  (qtp1955971146-31672) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948492 DEBUG (qtp1937897085-31621) [n:127.0.0.1:54064_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3948494 INFO  (qtp1937897085-31621) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=7
   [junit4]   2> 3948495 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 4
   [junit4]   2> 3948496 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
   [junit4]   2> 3948496 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_restore_trigger instantiated with properties: {event=nodeAdded, 
waitFor=0, actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 3948496 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 4
   [junit4]   2> 3948498 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3948499 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Adding node from 
marker path: 127.0.0.1:60345_solr
   [junit4]   2> 3948501 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_restore_trigger
   [junit4]   2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_restore_trigger firing registered processor for nodes: 
[127.0.0.1:60345_solr] added at times [2147034940848485], now=2147034943121521
   [junit4]   2> 3948501 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9",
   [junit4]   2>   "source":"node_added_restore_trigger",
   [junit4]   2>   "eventTime":2147034940848485,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147034940848485],
   [junit4]   2>     "nodeNames":["127.0.0.1:60345_solr"]}}
   [junit4]   2> 3948502 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 3948503 INFO  (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3948504 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9",
   [junit4]   2>   "source":"node_added_restore_trigger",
   [junit4]   2>   "eventTime":2147034940848485,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147034940848485],
   [junit4]   2>     "_enqueue_time_":2147034943399442,
   [junit4]   2>     "nodeNames":["127.0.0.1:60345_solr"]}}
   [junit4]   2> 3948505 INFO  
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState
   [junit4]   2> 3948516 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 12 
ms for event id=7a0b786f83965Tbs5gkwc63xlxd6sdmd1kwv4d9
   [junit4]   2> 3948683 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
   [junit4]   2> 3948683 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
   [junit4]   2> 3948684 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 5
   [junit4]   2> 3948684 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 5
   [junit4]   2> 3948688 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3948688 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3948689 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 3948693 INFO  (qtp1937897085-31623) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948694 INFO  (qtp1298289486-31614) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948695 INFO  (qtp1955971146-31676) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948695 DEBUG (qtp1955971146-31674) [n:127.0.0.1:60345_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3948696 INFO  (qtp1955971146-31674) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=4
   [junit4]   2> 3948696 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 6
   [junit4]   2> 3948697 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
   [junit4]   2> 3948697 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3948697 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 6
   [junit4]   2> 3948697 INFO  (qtp1937897085-31608) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948698 INFO  (qtp1298289486-31616) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948698 INFO  (qtp1955971146-31670) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3948698 DEBUG (qtp1955971146-31677) [n:127.0.0.1:60345_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3948699 INFO  (qtp1955971146-31677) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=3
   [junit4]   2> 3948700 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 7
   [junit4]   2> 3948700 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3948700 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
   [junit4]   2> 3948700 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3948700 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3948701 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:58429_solr, 127.0.0.1:60345_solr]
   [junit4]   2> 3948701 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3948701 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 6
   [junit4]   2> 3948701 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 7
   [junit4]   2> 3948701 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3948701 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3948704 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3948704 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 3948705 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3948705 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 3948705 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3948705 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3948706 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@55dacf4e{/solr,null,AVAILABLE}
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.AbstractConnector Started 
ServerConnector@5d54764b{HTTP/1.1,[http/1.1]}{127.0.0.1:33919}
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.Server Started @3953201ms
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=33919}
   [junit4]   2> 3948707 ERROR 
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port 
null
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 3948707 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-27T19:39:35.841Z
   [junit4]   2> 3948709 INFO  (zkConnectionManagerCallback-4805-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3948710 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 3948718 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34588/solr
   [junit4]   2> 3948720 INFO  (zkConnectionManagerCallback-4809-thread-1) [    
] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3948723 INFO  
(zkConnectionManagerCallback-4811-thread-1-processing-n:127.0.0.1:33919_solr) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 3948733 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 3948736 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 3948738 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33919_solr
   [junit4]   2> 3948740 INFO  
(zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3948742 INFO  
(zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3948742 INFO  
(zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) 
[n:127.0.0.1:60345_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3948742 INFO  (zkCallback-4792-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
   [junit4]   2> 3948743 INFO  
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (4)
   [junit4]   2> 3948879 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_33919.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3948885 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_33919.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3948885 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_33919.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@48c04b48
   [junit4]   2> 3948886 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001/tempDir-001/node4/.
   [junit4]   2> 3949703 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:33919_solr at time 2147036146069577
   [junit4]   2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147036146069577], now=2147036146172633
   [junit4]   2> 3949704 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":2147036146069577,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147036146069577],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3949706 INFO  (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3949706 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":2147036146069577,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147036146069577],
   [junit4]   2>     "_enqueue_time_":2147036146512691,
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3949706 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_added_trigger1
   [junit4]   2> 3949709 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 2 
ms for event id=7a0b7cece7049Tbs5gkwc63xlxd6sdmd1kwv4db
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:33919_solr at time 2147037163822023
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147037163822023], now=2147037163986288
   [junit4]   2> 3950721 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3950722 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dd",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3950722 INFO  (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147037163822023], now=2147038179893926
   [junit4]   2> 3951737 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4df",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3952741 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3952741 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3952741 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147037163822023], now=2147039184524364
   [junit4]   2> 3952742 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dg",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147037163822023], now=2147040186742926
   [junit4]   2> 3953743 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4dh",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3954744 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3954744 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
   [junit4]   2> 3954744 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:33919_solr] added at times [2147037163822023], now=2147041188043373
   [junit4]   2> 3954745 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3954746 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":2147037163822023,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147037163822023],
   [junit4]   2>     "_enqueue_time_":2147041188367959,
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3954747 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1514403576840000000 current time = 1514403581880000000
   [junit4]   2> real diff: 5040000000
   [junit4]   2>  min diff: 4998000000
   [junit4]   2> 3954747 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_added_trigger2
   [junit4]   2> 3954750 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 3 
ms for event id=7a0b80b781bc7Tbs5gkwc63xlxd6sdmd1kwv4di
   [junit4]   2> 3954752 INFO  (qtp1573688417-31701) [n:127.0.0.1:33919_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954754 INFO  (qtp1937897085-31618) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954757 INFO  (qtp1298289486-31619) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954759 INFO  (qtp1955971146-31673) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954760 DEBUG (qtp1955971146-31672) [n:127.0.0.1:60345_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3954761 INFO  (qtp1955971146-31672) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=12
   [junit4]   2> 3954762 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 8
   [junit4]   2> 3954764 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954764 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3954765 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954766 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954766 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3954766 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 8
   [junit4]   2> 3954766 INFO  (qtp1573688417-31703) [n:127.0.0.1:33919_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954768 INFO  (qtp1937897085-31617) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954771 INFO  (qtp1298289486-31609) [n:127.0.0.1:58429_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954772 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3954773 INFO  (qtp1955971146-31675) [n:127.0.0.1:60345_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics 
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0 
QTime=0
   [junit4]   2> 3954773 DEBUG (qtp1937897085-31620) [n:127.0.0.1:54064_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 3954774 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 8, lastZnodeVersion 8
   [junit4]   2> 3954775 INFO  (qtp1937897085-31620) [n:127.0.0.1:54064_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=11
   [junit4]   2> 3954775 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 4
   [junit4]   2> 3954776 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 9
   [junit4]   2> 3954777 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954777 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3954778 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954779 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954779 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
 enabled=true}
   [junit4]   2> 3954780 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:54064_solr, 127.0.0.1:33919_solr, 127.0.0.1:58429_solr, 
127.0.0.1:60345_solr]
   [junit4]   2> 3954780 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 9
   [junit4]   2> 3954788 INFO  
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 3954789 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 9, lastZnodeVersion 9
   [junit4]   2> 3954791 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 4
   [junit4]   2> 3954792 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.AbstractConnector Stopped 
ServerConnector@5d54764b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 3954792 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=411375952
   [junit4]   2> 3954792 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 3954792 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@36f36df4: rootName = 
solr_33919, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@111873a
   [junit4]   2> 3954802 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 3954802 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@7375684: rootName = 
solr_33919, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@1e8d67f
   [junit4]   2> 3954808 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 3954808 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@75f2c8d3: rootName = 
solr_33919, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@5cdb696a
   [junit4]   2> 3954811 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:33919_solr
   [junit4]   2> 3954812 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.cluster, tag=null
   [junit4]   2> 3954812 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 3954812 INFO  
(zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3954813 INFO  (zkCallback-4792-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
   [junit4]   2> 3954813 INFO  
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3954814 INFO  
(zkCallback-4782-thread-1-processing-n:127.0.0.1:54064_solr) 
[n:127.0.0.1:54064_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3954814 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from 
client sessionid 0x160997cae2b000e, likely client has closed socket
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
   [junit4]   2>        at 
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
   [junit4]   2>        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 3954814 INFO  
(zkCallback-4800-thread-1-processing-n:127.0.0.1:60345_solr) 
[n:127.0.0.1:60345_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (4) -> (3)
   [junit4]   2> 3955745 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3955746 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3955748 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3955748 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 
127.0.0.1:33919_solr
   [junit4]   2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3955777 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj",
   [junit4]   2>   "source":"node_lost_trigger1",
   [junit4]   2>   "eventTime":2147042220682177,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042220682177],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3955778 INFO  (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3955778 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj",
   [junit4]   2>   "source":"node_lost_trigger1",
   [junit4]   2>   "eventTime":2147042220682177,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042220682177],
   [junit4]   2>     "_enqueue_time_":2147042220859416,
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3955778 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_lost_trigger1
   [junit4]   2> 3955779 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 1 
ms for event id=7a0b938e1abc1Tbs5gkwc63xlxd6sdmd1kwv4dj
   [junit4]   2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 
127.0.0.1:33919_solr
   [junit4]   2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dl",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3955792 INFO  (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 3955792 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger 
processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
   [junit4]   2> 3956314 WARN  
(zkCallback-4810-thread-1-processing-n:127.0.0.1:33919_solr) 
[n:127.0.0.1:33919_solr    ] o.a.s.c.ZkController Unable to register nodeLost 
path for 127.0.0.1:33919_solr
   [junit4]   2> org.apache.zookeeper.KeeperException$SessionExpiredException: 
KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:33919_solr
   [junit4]   2>        at 
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2>        at 
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2>        at 
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:364)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:364)
   [junit4]   2>        at 
org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:879)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:704)
   [junit4]   2>        at 
java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
   [junit4]   2>        at 
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
   [junit4]   2>        at 
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:268)
   [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> 3956315 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@55dacf4e{/solr,null,UNAVAILABLE}
   [junit4]   2> 3956752 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3956752 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3956752 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3956752 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3956779 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3956793 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3956793 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3956794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dn",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3956794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger 
processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
   [junit4]   2> 3957753 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3957753 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3957753 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3957753 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3957780 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4do",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3957794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger 
processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
   [junit4]   2> 3958754 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3958754 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3958754 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3958754 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3958780 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3958794 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dp",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3958795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger 
processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
   [junit4]   2> 3959755 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3959756 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3959756 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3959756 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3959780 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dq",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3959795 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger 
processor for lost nodes: [127.0.0.1:33919_solr] is not ready, will try later
   [junit4]   2> 3960757 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 3960757 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 3960757 DEBUG (ScheduledTrigger-11018-thread-1) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3960757 DEBUG (ScheduledTrigger-11018-thread-4) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
   [junit4]   2> 3960780 DEBUG (ScheduledTrigger-11018-thread-3) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger1 with currently live nodes: 3
   [junit4]   2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
node_lost_trigger2 with currently live nodes: 3
   [junit4]   2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing 
registered processor for lost nodes: [127.0.0.1:33919_solr]
   [junit4]   2> 3960796 DEBUG (ScheduledTrigger-11018-thread-2) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3960797 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr",
   [junit4]   2>   "source":"node_lost_trigger2",
   [junit4]   2>   "eventTime":2147042236210260,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[2147042236210260],
   [junit4]   2>     "_enqueue_time_":2147047241146965,
   [junit4]   2>     "nodeNames":["127.0.0.1:33919_solr"]}}
   [junit4]   2> 3960798 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1514403582912000000 current time = 1514403587932000000
   [junit4]   2> real diff: 5020000000
   [junit4]   2>  min diff: 4998000000
   [junit4]   2> 3960798 INFO  
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_lost_trigger2
   [junit4]   2> 3960798 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[98C4F0A068D35A9F]) [   
 ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
   [junit4]   2> 3960830 DEBUG 
(AutoscalingActionExecutor-11019-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.ScheduledTriggers -- processing took 33 
ms for event id=7a0b939ce9c54Tbs5gkwc63xlxd6sdmd1kwv4dr
   [junit4]   2> 3960961 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
   [junit4]   2> 3960961 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode 
version 10
   [junit4]   2> 3960962 DEBUG 
(zkCallback-4780-thread-1-processing-n:127.0.0.1:58429_solr) 
[n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 10
   [junit4]   2> 3960962 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 10
   [junit4]   2> 3960971 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 3960971 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 3960972 DEBUG 
(OverseerAutoScalingTriggerThread-99247952579198981-127.0.0.1:58429_solr-n_0000000000)
 [n:127.0.0.1:58429_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 10, lastZnodeVersion 10
   [junit4]   2> 3960972 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 3960973 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@ced492d{/solr,null,AVAILABLE}
   [junit4]   2> 3960973 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.AbstractConnector Started 
ServerConnector@b3ebf76{HTTP/1.1,[http/1.1]}{127.0.0.1:38524}
   [junit4]   2> 3960973 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.e.j.s.Server Started @3965471ms
   [junit4]   2> 3960973 INFO  
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[98C4F0A068D35A9F])
 [    ] o.a.s.c.s.e.JettySolrRunne

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

l.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> 4122389 INFO  (jetty-closer-4765-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@2f5449f1{/solr,null,UNAVAILABLE}
   [junit4]   2> 4122393 ERROR 
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-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> 4122395 INFO  
(SUITE-TriggerIntegrationTest-seed#[98C4F0A068D35A9F]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:34588 34588
   [junit4]   2> 4127624 INFO  (Thread-8437) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:34588 34588
   [junit4]   2> 4127641 WARN  (Thread-8437) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        20      /solr/aliases.json
   [junit4]   2>        20      /solr/clusterprops.json
   [junit4]   2>        19      /solr/security.json
   [junit4]   2>        3       /solr/configs/conf
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        26      /solr/collections/testMetricTrigger/state.json
   [junit4]   2>        20      /solr/clusterstate.json
   [junit4]   2>        6       /solr/autoscaling.json
   [junit4]   2>        3       
/solr/overseer_elect/election/99247952579198987-127.0.0.1:60345_solr-n_0000000002
   [junit4]   2>        2       
/solr/overseer_elect/election/99247952579199005-127.0.0.1:48212_solr-n_0000000008
   [junit4]   2>        2       
/solr/overseer_elect/election/99247952579199021-127.0.0.1:63784_solr-n_0000000013
   [junit4]   2>        2       
/solr/overseer_elect/election/99247952579199015-127.0.0.1:65274_solr-n_0000000011
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        20      /solr/live_nodes
   [junit4]   2>        20      /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>        3       /solr/autoscaling/events/node_added_trigger
   [junit4]   2>        2       /solr/autoscaling/events/node_lost_trigger
   [junit4]   2> 
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/export/home/jenkins/workspace/Lucene-Solr-7.x-Solaris/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_98C4F0A068D35A9F-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{id=Lucene50(blocksize=128), x_s=PostingsFormat(name=MockRandom)}, 
docValues:{}, maxPointsInLeafNode=1216, maxMBSortInHeap=5.4596507488744495, 
sim=RandomSimilarity(queryNorm=true): {}, locale=es, timezone=Africa/Timbuktu
   [junit4]   2> NOTE: SunOS 5.11 amd64/Oracle Corporation 1.8.0_152 
(64-bit)/cpus=3,threads=1,free=292399688,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [RuleEngineTest, 
MultiThreadedOCPTest, ExitableDirectoryReaderTest, QueryResultKeyTest, 
BadComponentTest, HdfsRecoveryZkTest, TermVectorComponentTest, 
AnalysisAfterCoreReloadTest, BadCopyFieldTest, 
TestLMJelinekMercerSimilarityFactory, TestSolrQueryParser, MBeansHandlerTest, 
DistanceUnitsTest, TestHdfsUpdateLog, TestAuthenticationFramework, 
InfixSuggestersTest, BufferStoreTest, TestUniqueKeyFieldResource, 
TestRandomFlRTGCloud, ParsingFieldUpdateProcessorsTest, 
OutOfBoxZkACLAndCredentialsProvidersTest, TestPKIAuthenticationPlugin, 
SystemInfoHandlerTest, TestNumericRangeQuery64, TestUtilizeNode, 
TestMultiWordSynonyms, TestReplicationHandlerBackup, SimpleFacetsTest, 
BasicZkTest, TestFieldTypeResource, TestCrossCoreJoin, TestCryptoKeys, 
TestPayloadScoreQParserPlugin, TestRawResponseWriter, TestCharFilters, 
TestPostingsSolrHighlighter, CollectionsAPIDistributedZkTest, TestPullReplica, 
TestConfigSetsAPIExclusivity, TestLuceneMatchVersion, 
ClassificationUpdateProcessorFactoryTest, TestTrie, EchoParamsTest, 
DocumentAnalysisRequestHandlerTest, TestSolrConfigHandlerConcurrent, 
DeleteLastCustomShardedReplicaTest, DistributedQueryComponentCustomSortTest, 
TestCollationField, TestSolrCloudWithKerberosAlt, TestSkipOverseerOperations, 
TestConfigsApi, LukeRequestHandlerTest, TestInPlaceUpdatesStandalone, 
DocValuesNotIndexedTest, TestCloudPivotFacet, PolyFieldTest, ZkStateWriterTest, 
ExternalFileFieldSortTest, TestAnalyzedSuggestions, 
LeaderInitiatedRecoveryOnCommitTest, TestSimpleTrackingShardHandler, 
CacheHeaderTest, SuggestComponentContextFilterQueryTest, 
TestSuggestSpellingConverter, TestMergePolicyConfig, PreAnalyzedFieldTest, 
TestSimDistributedQueue, TestDistribIDF, ComputePlanActionTest, TestDocSet, 
TestNodeLostTrigger, TestLegacyFieldCache, CachingDirectoryFactoryTest, 
DebugComponentTest, WrapperMergePolicyFactoryTest, TestConfig, 
TestSQLHandlerNonCloud, TestCollapseQParserPlugin, TestNumericTerms64, 
TestLeaderInitiatedRecoveryThread, TestInitQParser, TestSolrConfigHandler, 
TestUseDocValuesAsStored, TestRandomFaceting, TestXmlQParser, 
TestGraphTermsQParserPlugin, JsonLoaderTest, TestQueryTypes, CoreSorterTest, 
SolrGraphiteReporterTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, 
HdfsLockFactoryTest, TermsComponentTest, PeerSyncTest, 
TestGeoJSONResponseWriter, BigEndianAscendingWordSerializerTest, 
HdfsBasicDistributedZkTest, SolrPluginUtilsTest, ReplaceNodeTest, 
ChangedSchemaMergeTest, TestCloudInspectUtil, TestStressLucene, 
SearchHandlerTest, TestGroupingSearch, FieldMutatingUpdateProcessorTest, 
SSLMigrationTest, SystemLogListenerTest, TestOrdValues, DocValuesMultiTest, 
OpenCloseCoreStressTest, TestPartialUpdateDeduplication, SparseHLLTest, 
PKIAuthenticationIntegrationTest, BaseCdcrDistributedZkTest, 
TestExclusionRuleCollectionAccess, TestOnReconnectListenerSupport, 
CustomCollectionTest, TestRTGBase, TestSolrJ, 
TestDistributedStatsComponentCardinality, ZkFailoverTest, VersionInfoTest, 
SOLR749Test, SpellPossibilityIteratorTest, 
CollectionsAPIAsyncDistributedZkTest, TestZkAclsWithHadoopAuth, 
HLLSerializationTest, TestBadConfig, TestSearchPerf, MergeStrategyTest, 
RecoveryAfterSoftCommitTest, TestRequestForwarding, LoggingHandlerTest, 
DOMUtilTest, QueryElevationComponentTest, DistributedMLTComponentTest, 
HdfsChaosMonkeySafeLeaderTest, DirectSolrSpellCheckerTest, 
TestComplexPhraseQParserPlugin, SpatialRPTFieldTypeTest, 
TestExtendedDismaxParser, TestLegacyField, ShardSplitTest, 
OverseerTaskQueueTest, TestElisionMultitermQuery, 
AutoscalingHistoryHandlerTest, SoftAutoCommitTest, TestFieldSortValues, 
TestConfigOverlay, ZkSolrClientTest, TestManagedSchemaThreadSafety, 
CollectionStateFormat2Test, SimplePostToolTest, 
TestTolerantUpdateProcessorCloud, TestLeaderElectionWithEmptyReplica, 
MetricTriggerTest, TestHashPartitioner, TestZkChroot, TestSystemIdResolver, 
TestLuceneIndexBackCompat, AtomicUpdateProcessorFactoryTest, TestJsonFacets, 
TestMaxScoreQueryParser, QueryEqualityTest, TestFieldCacheVsDocValues, 
HttpPartitionTest, TestStressReorder, SpellCheckCollatorWithCollapseTest, 
TestDocBasedVersionConstraints, TestIndexSearcher, TestFieldCache, 
TestFieldCacheSort, DateRangeFieldTest, TestClusterStateMutator, 
TestFastLRUCache, UpdateParamsTest, MissingSegmentRecoveryTest, TestCoreBackup, 
SolrJmxReporterTest, HdfsTlogReplayBufferedWhileIndexingTest, 
TestPerFieldSimilarity, GraphQueryTest, TestConfigSetProperties, 
TestSolr4Spatial2, TestDistributedMissingSort, DocumentBuilderTest, 
InfoHandlerTest, BasicDistributedZkTest, TestReplicationHandler, 
TestDistributedGrouping, TestFaceting, TermVectorComponentDistributedTest, 
ZkControllerTest, TestStressVersions, SolrCoreTest, SolrCmdDistributorTest, 
TestFunctionQuery, TestLazyCores, SignatureUpdateProcessorFactoryTest, 
CoreAdminHandlerTest, DocValuesTest, TestRemoteStreaming, DistanceFunctionTest, 
TestSurroundQueryParser, TestQueryUtils, TestReversedWildcardFilterFactory, 
FileBasedSpellCheckerTest, RequestHandlersTest, TestValueSourceCache, 
RequiredFieldsTest, FieldAnalysisRequestHandlerTest, 
IndexSchemaRuntimeFieldTest, UpdateRequestProcessorFactoryTest, 
QueryParsingTest, CSVRequestHandlerTest, TestComponentsName, 
HighlighterConfigTest, TestQuerySenderListener, TestSolrIndexConfig, 
CopyFieldTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, MultiTermTest, 
SampleTest, TestBinaryField, NumericFieldsTest, OutputWriterTest, 
DirectSolrConnectionTest, TestPhraseSuggestions, SynonymTokenizerTest, 
TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, 
TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, 
ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, 
OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, PluginInfoTest, 
PrimUtilsTest, DateFieldTest, SpellingQueryConverterTest, TestLRUCache, 
TestUtils, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, UUIDFieldTest, 
FileUtilsTest, CircularListTest, CursorPagingTest, SolrTestCaseJ4Test, 
TestJettySolrRunner, ConnectionReuseTest, AliasIntegrationTest, AssignTest, 
CloudExitableDirectoryReaderTest, ConcurrentDeleteAndCreateCollectionTest, 
ConfigSetsAPITest, CreateCollectionCleanupTest, DeleteShardTest, 
DistribCursorPagingTest, DistribJoinFromCollectionTest, DistributedQueueTest, 
LeaderFailoverAfterPartitionTest, MoveReplicaHDFSTest, SolrCloudExampleTest, 
TestCloudRecovery, TestDistribDocBasedVersion, TestLeaderElectionZkExpiry, 
TestLockTree, TestPullReplicaErrorHandling, TestRequestStatusCollectionAPI, 
TestSolrCloudWithDelegationTokens, TestSolrCloudWithSecureImpersonation, 
VMParamsZkACLAndCredentialsProvidersTest, AutoScalingHandlerTest, 
HdfsAutoAddReplicasIntegrationTest, TriggerIntegrationTest]
   [junit4] Completed [579/764 (1!)] on J1 in 181.55s, 14 tests, 1 failure, 1 
skipped <<< FAILURES!

[...truncated 48758 lines...]

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org