Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4311/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
Both triggers should have fired by now

Stack Trace:
java.lang.AssertionError: Both triggers should have fired by now
        at 
__randomizedtesting.SeedInfo.seed([5F2613B39B3D5486:A404BB964997B714]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at 
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testTriggerThrottling(TriggerIntegrationTest.java:205)
        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 12530 lines...]
   [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/init-core-data-001
   [junit4]   2> 1169209 WARN  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=19 numCloses=19
   [junit4]   2> 1169209 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 1169213 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) 
w/ MAC_OS_X supressed clientAuth
   [junit4]   2> 1169213 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 1169214 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/tempDir-001
   [junit4]   2> 1169214 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1169215 INFO  (Thread-2199) [    ] o.a.s.c.ZkTestServer client 
port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1169215 INFO  (Thread-2199) [    ] o.a.s.c.ZkTestServer 
Starting server
   [junit4]   2> 1169218 ERROR (Thread-2199) [    ] 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> 1169315 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.ZkTestServer start zk server on port:49857
   [junit4]   2> 1169347 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 1169347 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 1169349 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@3ec7747d{/solr,null,AVAILABLE}
   [junit4]   2> 1169349 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@12de73c2{/solr,null,AVAILABLE}
   [junit4]   2> 1169349 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@382e5020{HTTP/1.1,[http/1.1]}{127.0.0.1:49859}
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.e.j.s.Server Started @1174727ms
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=49859}
   [junit4]   2> 1169350 ERROR (jetty-launcher-1586-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@14d59fe4{HTTP/1.1,[http/1.1]}{127.0.0.1:49860}
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.e.j.s.Server Started @1174728ms
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=49860}
   [junit4]   2> 1169350 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-04T11:12:35.246Z
   [junit4]   2> 1169350 ERROR (jetty-launcher-1586-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1169351 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 1169351 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1169351 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1169351 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-04T11:12:35.247Z
   [junit4]   2> 1169359 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1169359 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1169370 INFO  (jetty-launcher-1586-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49857/solr
   [junit4]   2> 1169370 INFO  (jetty-launcher-1586-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49857/solr
   [junit4]   2> 1169583 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1169583 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1169584 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:49860_solr
   [junit4]   2> 1169585 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49859_solr
   [junit4]   2> 1169587 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.Overseer Overseer 
(id=99115725954285574-127.0.0.1:49860_solr-n_0000000000) starting
   [junit4]   2> 1169588 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1169588 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1169600 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 1169601 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 1
   [junit4]   2> 1169602 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeLostTrigger Initial livenodes: 
[127.0.0.1:49859_solr]
   [junit4]   2> 1169602 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion -1
   [junit4]   2> 1169602 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 1
   [junit4]   2> 1169603 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49860_solr
   [junit4]   2> 1169608 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1169609 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (1) -> (2)
   [junit4]   2> 1169609 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 1169610 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 1, lastZnodeVersion 1
   [junit4]   2> 1169610 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: 
.auto_add_replicas with currently live nodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1169725 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49859.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169740 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49859.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169741 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49859.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169742 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49860.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169744 INFO  (jetty-launcher-1586-thread-1) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/tempDir-001/node1/.
   [junit4]   2> 1169775 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49860.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169775 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49860.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1169780 INFO  (jetty-launcher-1586-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/tempDir-001/node2/.
   [junit4]   2> 1169805 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 0x160213a45290007, 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> 1169813 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1169814 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49857/solr ready
   [junit4]   2> 1169832 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testSetProperties
   [junit4]   2> 1169833 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
   [junit4]   2> 1169833 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 2
   [junit4]   2> 1169833 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 2
   [junit4]   2> 1169836 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1169837 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 1169837 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 2, lastZnodeVersion 2
   [junit4]   2> 1170847 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: 
triggerScheduleDelaySeconds from: 1 to: 4
   [junit4]   2> 1178854 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: 
triggerScheduleDelaySeconds from: 4 to: 1
   [junit4]   2> 1188875 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: 
triggerCorePoolSize from: 4 to: 6
   [junit4]   2> 1198909 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: 
actionThrottlePeriodSeconds from: 5 to: 6
   [junit4]   2> 1198920 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1198920 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y1 instantiated with properties: 
{waitFor=0, actions=[{name=throttler, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}]}
   [junit4]   2> 1198923 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
   [junit4]   2> 1198925 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1198925 DEBUG 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 instantiated with properties: 
{waitFor=0, actions=[{name=throttler, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}]}
   [junit4]   2> 1198926 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1198926 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1198928 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
   [junit4]   2> 1198929 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 1198930 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1198930 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1198931 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@13528aad{/solr,null,AVAILABLE}
   [junit4]   2> 1198931 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4d22e7bb{HTTP/1.1,[http/1.1]}{127.0.0.1:49904}
   [junit4]   2> 1198931 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.Server Started @1204309ms
   [junit4]   2> 1198931 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=49904}
   [junit4]   2> 1198932 ERROR 
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1198932 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 1198932 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1198932 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1198933 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-04T11:13:04.829Z
   [junit4]   2> 1198935 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1198947 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49857/solr
   [junit4]   2> 1198967 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1198971 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1198974 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49904_solr
   [junit4]   2> 1198977 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1198977 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1198978 INFO  
(zkCallback-1611-thread-1-processing-n:127.0.0.1:49904_solr) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1198978 INFO  (zkCallback-1605-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1199108 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49904.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1199119 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49904.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1199119 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49904.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1199126 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/tempDir-001/node3/.
   [junit4]   2> 1199935 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1199935 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:49904_solr at time 
1512385985832000000
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385985832000000
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:49904_solr at time 
1512385985832000000
   [junit4]   2> 1199937 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y1 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385985833000000
   [junit4]   2> 1199937 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tas",
   [junit4]   2>   "source":"y1",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1199936 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tar",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1199940 DEBUG (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tas",
   [junit4]   2>   "source":"y1",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "_enqueue_time_":1512385985833000000,
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1199940 INFO  (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.a.TriggerIntegrationTest action executed from y1
   [junit4]   2> 1200943 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1200943 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1200943 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385986839000000
   [junit4]   2> 1200943 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tat",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1200944 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1200944 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385987843000000
   [junit4]   2> 1201947 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tau",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1202949 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1202949 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1202949 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1202949 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385988845000000
   [junit4]   2> 1202949 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1202950 DEBUG (ScheduledTrigger-4596-thread-2) [    ] 
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tav",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1203959 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1203959 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1203959 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1203959 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1203960 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385989856000000
   [junit4]   2> 1203960 DEBUG (ScheduledTrigger-4596-thread-1) [    ] 
o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7taw",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr, 127.0.0.1:49904_solr]
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger y2 firing registered processor for 
nodes: [127.0.0.1:49904_solr] added at times [1512385985832000000], 
now=1512385990863000000
   [junit4]   2> 1204967 DEBUG (ScheduledTrigger-4596-thread-3) [    ] 
o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tax",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1204968 DEBUG (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.a.ScheduledTriggers -- processing actions for {
   [junit4]   2>   "id":"14fd130a88cb9a00Tt4q92qrxgo5g6cqtz45d7tax",
   [junit4]   2>   "source":"y2",
   [junit4]   2>   "eventTime":1512385985832000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385985832000000],
   [junit4]   2>     "_enqueue_time_":1512385990863000000,
   [junit4]   2>     "nodeNames":["127.0.0.1:49904_solr"]}}
   [junit4]   2> 1204969 INFO  (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.ActionThrottle The last action attempt started 5028ms ago.
   [junit4]   2> 1204969 INFO  (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.ActionThrottle Throttling action attempts - waiting for 971ms
   [junit4]   2> 1205941 INFO  (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.a.TriggerIntegrationTest last action at 1512385985837000000 time = 
1512385991837000000 expected diff: 5998000000
   [junit4]   2> 1205941 INFO  (AutoscalingActionExecutor-4597-thread-1) [    ] 
o.a.s.c.a.TriggerIntegrationTest action executed from y2
   [junit4]   2> 1205942 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@4d22e7bb{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1205943 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=45615294
   [junit4]   2> 1205943 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 1205943 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@38fa63a2: rootName = 
solr_49904, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@14c0eba1
   [junit4]   2> 1205952 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 1205953 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@256a2cee: rootName = 
solr_49904, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@5efdf7a7
   [junit4]   2> 1205959 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 1205959 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@2eff77f4: rootName = 
solr_49904, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@dfd692e
   [junit4]   2> 1205962 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49904_solr
   [junit4]   2> 1205963 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 1205964 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 1205964 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1205965 INFO  
(zkCallback-1611-thread-1-processing-n:127.0.0.1:49904_solr) 
[n:127.0.0.1:49904_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1205965 INFO  (zkCallback-1605-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 1205965 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1205966 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@13528aad{/solr,null,UNAVAILABLE}
   [junit4]   2> 1205973 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y1
   [junit4]   2> 1205973 DEBUG (ScheduledTrigger-4596-thread-4) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1205973 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger y2
   [junit4]   2> 1205973 DEBUG (ScheduledTrigger-4596-thread-6) [    ] 
o.a.s.c.a.NodeAddedTrigger Found livenodes: [127.0.0.1:49859_solr, 
127.0.0.1:49860_solr]
   [junit4]   2> 1205979 INFO  
(TEST-TriggerIntegrationTest.testSetProperties-seed#[5F2613B39B3D5486]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending testSetProperties
   [junit4]   2> 1205995 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
   [junit4]   2> 1205995 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 3
   [junit4]   2> 1205996 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 3
   [junit4]   2> 1205997 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 3
   [junit4]   2> 1205997 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1205997 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 1205998 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 3, lastZnodeVersion 3
   [junit4]   2> 1206032 INFO  (qtp1581366924-9393) [n:127.0.0.1:49860_solr    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1206034 INFO  (qtp1581366924-9393) [n:127.0.0.1:49860_solr    
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49857/solr ready
   [junit4]   2> 1206039 INFO  (qtp1317163789-9385) [n:127.0.0.1:49859_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> 1206041 INFO  (qtp1581366924-9395) [n:127.0.0.1:49860_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> 1206042 DEBUG (qtp1581366924-9393) [n:127.0.0.1:49860_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1206044 INFO  (qtp1581366924-9393) [n:127.0.0.1:49860_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling 
params={wt=javabin&version=2} status=0 QTime=18
   [junit4]   2> 1206045 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 4
   [junit4]   2> 1206047 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1206048 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_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> 1206048 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 4
   [junit4]   2> 1206053 INFO  
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 1206054 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1206054 INFO  (qtp1317163789-9385) [n:127.0.0.1:49859_solr    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 1206055 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 4, lastZnodeVersion 4
   [junit4]   2> 1206055 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1206055 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1206056 INFO  (qtp1317163789-9385) [n:127.0.0.1:49859_solr    
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49857/solr ready
   [junit4]   2> 1206058 INFO  (qtp1317163789-9387) [n:127.0.0.1:49859_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> 1206061 INFO  (qtp1581366924-9396) [n:127.0.0.1:49860_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> 1206061 DEBUG (qtp1317163789-9385) [n:127.0.0.1:49859_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1206064 INFO  (qtp1317163789-9385) [n:127.0.0.1:49859_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=17
   [junit4]   2> 1206065 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 5
   [junit4]   2> 1206066 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1206066 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_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> 1206067 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1206067 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_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> 1206068 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 5
   [junit4]   2> 1206071 INFO  
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 1206073 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.e.j.s.Server jetty-9.3.20.v20170531
   [junit4]   2> 1206074 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1206075 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 5, lastZnodeVersion 5
   [junit4]   2> 1206075 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1206075 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1206076 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@ccfa497{/solr,null,AVAILABLE}
   [junit4]   2> 1206077 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.e.j.s.AbstractConnector Started 
ServerConnector@dab2612{HTTP/1.1,[http/1.1]}{127.0.0.1:49940}
   [junit4]   2> 1206077 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.e.j.s.Server Started @1211455ms
   [junit4]   2> 1206077 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=49940}
   [junit4]   2> 1206077 ERROR 
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1206078 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
8.0.0
   [junit4]   2> 1206078 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port 
null
   [junit4]   2> 1206078 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1206078 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-12-04T11:13:11.974Z
   [junit4]   2> 1206091 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1206137 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49857/solr
   [junit4]   2> 1206167 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1206172 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 1206177 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49940_solr
   [junit4]   2> 1206180 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1206180 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1206180 INFO  (zkCallback-1605-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1206181 INFO  
(zkCallback-1623-thread-1-processing-n:127.0.0.1:49940_solr) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (3)
   [junit4]   2> 1206303 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49940.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1206316 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49940.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1206317 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_49940.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@36ec2e87
   [junit4]   2> 1206318 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001/tempDir-001/node4/.
   [junit4]   2> 1207067 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1207067 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1207067 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:49940_solr at time 1512385992963000000
   [junit4]   2> 1207067 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger1 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992963000000], 
now=1512385992963000000
   [junit4]   2> 1207068 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"14fd130c31d606c0Tt4q92qrxgo5g6cqtz45d7tay",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1512385992963000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992963000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1207068 INFO  (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 1207069 DEBUG 
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"14fd130c31d606c0Tt4q92qrxgo5g6cqtz45d7tay",
   [junit4]   2>   "source":"node_added_trigger1",
   [junit4]   2>   "eventTime":1512385992963000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992963000000],
   [junit4]   2>     "_enqueue_time_":1512385992964000000,
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1207069 INFO  
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1512385991837000000 time = 1512385992965000000 expected diff: 4998000000
   [junit4]   2> 1207069 INFO  
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
again before minimum wait time from node_added_trigger1
   [junit4]   2> 1207087 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1207087 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1207087 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 
127.0.0.1:49940_solr at time 1512385992983000000
   [junit4]   2> 1207087 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385992983000000
   [junit4]   2> 1207087 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb0",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1207087 INFO  (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.SystemLogListener Collection .system 
does not exist, disabling logging.
   [junit4]   2> 1208078 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1208078 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1208089 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1208089 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1208089 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385993985000000
   [junit4]   2> 1208089 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb2",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1209082 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1209082 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1209091 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1209091 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1209091 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385994987000000
   [junit4]   2> 1209091 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb3",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1210086 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1210086 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1210095 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1210095 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1210095 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385995991000000
   [junit4]   2> 1210095 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb4",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1211093 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1211093 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1211096 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1211096 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1211097 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385996993000000
   [junit4]   2> 1211097 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -------- Cooldown 
period - rejecting event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb5",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger2 firing registered processor for nodes: 
[127.0.0.1:49940_solr] added at times [1512385992983000000], 
now=1512385997994000000
   [junit4]   2> 1212098 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown 
inactive - processing event: {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb6",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1212099 DEBUG 
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.ScheduledTriggers -- processing actions 
for {
   [junit4]   2>   "id":"14fd130c330733c0Tt4q92qrxgo5g6cqtz45d7tb6",
   [junit4]   2>   "source":"node_added_trigger2",
   [junit4]   2>   "eventTime":1512385992983000000,
   [junit4]   2>   "eventType":"NODEADDED",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[1512385992983000000],
   [junit4]   2>     "_enqueue_time_":1512385997994000000,
   [junit4]   2>     "nodeNames":["127.0.0.1:49940_solr"]}}
   [junit4]   2> 1212099 INFO  
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.ActionThrottle The last action attempt 
started 5030ms ago.
   [junit4]   2> 1212100 INFO  
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest last action at 
1512385991837000000 time = 1512385997996000000 expected diff: 4998000000
   [junit4]   2> 1212100 INFO  
(AutoscalingActionExecutor-4590-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest action executed 
from node_added_trigger2
   [junit4]   2> 1213099 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1213099 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1213101 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1213101 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1214107 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1214107 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1214107 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1214107 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1215109 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1215109 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1215109 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1215109 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1216122 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1216122 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1216122 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1216122 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1217132 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1217132 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1217132 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1217142 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1218134 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1218134 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1218144 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1218144 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1219149 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1219149 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1219149 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1219149 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1220154 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1220154 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1220154 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1220154 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1221155 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1221155 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1221155 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1221155 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1222155 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1222156 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1222156 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1222156 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1223165 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1223165 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1223165 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1223165 DEBUG (ScheduledTrigger-4589-thread-1) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1224175 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1224175 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1224175 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1224175 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1225185 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1225185 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1225185 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1225185 DEBUG (ScheduledTrigger-4589-thread-4) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1226191 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger1
   [junit4]   2> 1226191 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1226191 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger2
   [junit4]   2> 1226191 DEBUG (ScheduledTrigger-4589-thread-2) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1226387 INFO  
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[5F2613B39B3D5486]) [   
 ] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TriggerIntegrationTest -Dtests.method=testTriggerThrottling 
-Dtests.seed=5F2613B39B3D5486 -Dtests.slow=true -Dtests.locale=en-AU 
-Dtests.timezone=America/Argentina/Salta -Dtests.asserts=true 
-Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 20.4s J1 | TriggerIntegrationTest.testTriggerThrottling <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Both triggers should 
have fired by now
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([5F2613B39B3D5486:A404BB964997B714]:0)
   [junit4]    >        at 
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testTriggerThrottling(TriggerIntegrationTest.java:205)
   [junit4]    >        at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 1226411 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testContinueTriggersOnOverseerRestart
   [junit4]   2> 1226411 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode 
version 6
   [junit4]   2> 1226412 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 6
   [junit4]   2> 1226412 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 6
   [junit4]   2> 1226415 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1226416 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeAdded markers
   [junit4]   2> 1226416 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 6, lastZnodeVersion 6
   [junit4]   2> 1226418 INFO  (qtp1317163789-9388) [n:127.0.0.1:49859_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with 
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 1226428 INFO  (qtp1317163789-9388) [n:127.0.0.1:49859_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=10
   [junit4]   2> 1226438 INFO  (qtp1317163789-9389) [n:127.0.0.1:49859_solr    
] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 1226440 INFO  (qtp1317163789-9389) [n:127.0.0.1:49859_solr    
] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:49857/solr ready
   [junit4]   2> 1226447 INFO  (qtp1136909555-9483) [n:127.0.0.1:49940_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> 1226449 INFO  (qtp1317163789-9390) [n:127.0.0.1:49859_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> 1226452 INFO  (qtp1581366924-9397) [n:127.0.0.1:49860_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> 1226453 DEBUG (qtp1317163789-9389) [n:127.0.0.1:49859_solr    
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
   [junit4]   2> 1226455 INFO  (qtp1317163789-9389) [n:127.0.0.1:49859_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling 
params={wt=javabin&version=2} status=0 QTime=23
   [junit4]   2> 1226455 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 7
   [junit4]   2> 1226456 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1226456 DEBUG 
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 1226456 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Processed trigger 
updates upto znodeVersion 7
   [junit4]   2> 1226459 INFO  
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.TriggerIntegrationTest 
TestTriggerAction init
   [junit4]   2> 1226460 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.e.j.s.AbstractConnector Stopped 
ServerConnector@14d59fe4{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1226460 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread -- clean old 
nodeLost markers
   [junit4]   2> 1226460 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1813744574
   [junit4]   2> 1226461 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.node, tag=null
   [junit4]   2> 1226461 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@4ce691cd: rootName = 
solr_49860, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@688dee4a
   [junit4]   2> 1226463 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread Current 
znodeVersion 7, lastZnodeVersion 7
   [junit4]   2> 1226463 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Running 
NodeAddedTrigger node_added_trigger
   [junit4]   2> 1226463 DEBUG (ScheduledTrigger-4589-thread-3) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr, 127.0.0.1:49860_solr]
   [junit4]   2> 1226468 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jvm, tag=null
   [junit4]   2> 1226469 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@f134b89: rootName = 
solr_49860, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@5efdf7a7
   [junit4]   2> 1226473 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jetty, tag=null
   [junit4]   2> 1226473 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@453b37a7: rootName = 
solr_49860, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@dfd692e
   [junit4]   2> 1226475 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:49860_solr
   [junit4]   2> 1226477 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.cluster, tag=null
   [junit4]   2> 1226478 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 1226481 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.Overseer Overseer 
(id=99115725954285574-127.0.0.1:49860_solr-n_0000000000) closing
   [junit4]   2> 1226481 INFO  
(OverseerStateUpdate-99115725954285574-127.0.0.1:49860_solr-n_0000000000) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:49860_solr
   [junit4]   2> 1226482 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1226483 INFO  (zkCallback-1605-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 1226483 INFO  
(zkCallback-1597-thread-1-processing-n:127.0.0.1:49860_solr) 
[n:127.0.0.1:49860_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1226483 INFO  
(zkCallback-1623-thread-1-processing-n:127.0.0.1:49940_solr) 
[n:127.0.0.1:49940_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (3) -> (2)
   [junit4]   2> 1226483 WARN  
(OverseerAutoScalingTriggerThread-99115725954285574-127.0.0.1:49860_solr-n_0000000000)
 [n:127.0.0.1:49860_solr    ] o.a.s.c.a.OverseerTriggerThread 
OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1226487 DEBUG 
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed 
explicitly
   [junit4]   2> 1226489 INFO  
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[5F2613B39B3D5486])
 [    ] o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@12de73c2{/solr,null,UNAVAILABLE}
   [junit4]   2> 1226489 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:49859_solr
   [junit4]   2> 1226491 INFO  
(zkCallback-1598-thread-1-processing-n:127.0.0.1:49859_solr) 
[n:127.0.0.1:49859_solr    ] o.a.s.c.Overseer Overseer 
(id=99115725954285573-127.0.0.1:49859_solr-n_0000000001) starting
   [junit4]   2> 1226501 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285573-127.0.0.1:49859_solr-n_0000000001)
 [n:127.0.0.1:49859_solr    ] o.a.s.c.a.OverseerTriggerThread Adding 
.autoAddReplicas trigger
   [junit4]   2> 1226503 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285573-127.0.0.1:49859_solr-n_0000000001)
 [n:127.0.0.1:49859_solr    ] o.a.s.c.a.OverseerTriggerThread Refreshing 
/autoscaling.json with znode version 8
   [junit4]   2> 1226505 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285573-127.0.0.1:49859_solr-n_0000000001)
 [n:127.0.0.1:49859_solr    ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: 
[127.0.0.1:49940_solr, 127.0.0.1:49859_solr]
   [junit4]   2> 1226505 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285573-127.0.0.1:49859_solr-n_0000000001)
 [n:127.0.0.1:49859_solr    ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger 
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, 
actions=[{name=test, 
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
 enabled=true}
   [junit4]   2> 1226505 DEBUG 
(OverseerAutoScalingTriggerThread-99115725954285573-127.0

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

FO  (jetty-closer-1587-thread-3) [    ] o.a.s.c.TransientSolrCoreCacheDefault 
Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 1348189 INFO  
(zkCallback-1654-thread-2-processing-n:127.0.0.1:50111_solr) 
[n:127.0.0.1:50111_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (0)
   [junit4]   2> 1348190 INFO  
(zkCallback-1669-thread-1-processing-n:127.0.0.1:50142_solr) 
[n:127.0.0.1:50142_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (0)
   [junit4]   2> 1348190 INFO  
(zkCallback-1699-thread-2-processing-n:127.0.0.1:50228_solr) 
[n:127.0.0.1:50228_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (2) -> (0)
   [junit4]   2> 1348192 INFO  (jetty-closer-1587-thread-3) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@33d37c86{/solr,null,UNAVAILABLE}
   [junit4]   2> 1348227 INFO  (coreCloseExecutor-4733-thread-1) 
[n:127.0.0.1:50111_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=295863517
   [junit4]   2> 1348231 INFO  (coreCloseExecutor-4738-thread-1) 
[n:127.0.0.1:50228_solr c:collection1 s:shard1 r:core_node4 
x:collection1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=1084623639
   [junit4]   2> 1348236 INFO  (jetty-closer-1587-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=99115725954285597-127.0.0.1:50111_solr-n_0000000006) closing
   [junit4]   2> 1348236 INFO  
(OverseerStateUpdate-99115725954285597-127.0.0.1:50111_solr-n_0000000006) 
[n:127.0.0.1:50111_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:50111_solr
   [junit4]   2> 1348237 WARN  
(OverseerAutoScalingTriggerThread-99115725954285597-127.0.0.1:50111_solr-n_0000000006)
 [n:127.0.0.1:50111_solr    ] o.a.s.c.a.OverseerTriggerThread 
OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 1348238 DEBUG (jetty-closer-1587-thread-1) [    ] 
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
   [junit4]   2> 1348240 INFO  (jetty-closer-1587-thread-6) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@2ec02446{/solr,null,UNAVAILABLE}
   [junit4]   2> 1348242 INFO  (jetty-closer-1587-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@699481e{/solr,null,UNAVAILABLE}
   [junit4]   2> 1349625 WARN  
(zkCallback-1730-thread-1-processing-n:127.0.0.1:50369_solr) 
[n:127.0.0.1:50369_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1349626 INFO  (jetty-closer-1587-thread-8) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@52570f92{/solr,null,UNAVAILABLE}
   [junit4]   2> 1349664 INFO  (jetty-closer-1587-thread-9) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@2b4e2cd5{/solr,null,UNAVAILABLE}
   [junit4]   2> 1349697 WARN  
(zkCallback-1684-thread-2-processing-n:127.0.0.1:50189_solr) 
[n:127.0.0.1:50189_solr    ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, 
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
   [junit4]   2> 1349698 INFO  (jetty-closer-1587-thread-4) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@51cb8267{/solr,null,UNAVAILABLE}
   [junit4]   2> 1349699 ERROR 
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-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> 1349700 INFO  
(SUITE-TriggerIntegrationTest-seed#[5F2613B39B3D5486]-worker) [    ] 
o.a.s.c.ZkTestServer connecting to 127.0.0.1:49857 49857
   [junit4]   2> 1349722 INFO  (Thread-2199) [    ] o.a.s.c.ZkTestServer 
connecting to 127.0.0.1:49857 49857
   [junit4]   2> 1350148 WARN  (Thread-2199) [    ] o.a.s.c.ZkTestServer Watch 
limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2>        42      /solr/aliases.json
   [junit4]   2>        42      /solr/clusterprops.json
   [junit4]   2>        18      /solr/security.json
   [junit4]   2>        2       /solr/configs/conf
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        42      /solr/clusterstate.json
   [junit4]   2>        16      /solr/collections/collection1/state.json
   [junit4]   2>        6       /solr/autoscaling.json
   [junit4]   2>        3       
/solr/overseer_elect/election/99115725954285597-127.0.0.1:50111_solr-n_0000000006
   [junit4]   2>        2       
/solr/overseer_elect/election/99115725954285610-127.0.0.1:50189_solr-n_0000000009
   [junit4]   2>        2       
/solr/overseer_elect/election/99115725954285620-127.0.0.1:50268_solr-n_0000000012
   [junit4]   2>        2       
/solr/overseer_elect/election/99115725954285573-127.0.0.1:49859_solr-n_0000000001
   [junit4]   2>        2       
/solr/overseer_elect/election/99115725954285617-127.0.0.1:50228_solr-n_0000000011
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        42      /solr/live_nodes
   [junit4]   2>        42      /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: 
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5F2613B39B3D5486-001
   [junit4]   2> NOTE: test params are: 
codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=26018, maxDocsPerChunk=4, blockSize=968), 
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION,
 chunkSize=26018, blockSize=968)), 
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@75fd12e3),
 locale=en-AU, timezone=America/Argentina/Salta
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_144 
(64-bit)/cpus=3,threads=1,free=99998152,total=223256576
   [junit4]   2> NOTE: All tests run in this JVM: 
[PeerSyncWithIndexFingerprintCachingTest, TestPushWriter, 
LukeRequestHandlerTest, LargeFieldTest, TestHalfAndHalfDocValues, 
TestRemoteStreaming, PeerSyncTest, CacheHeaderTest, ZkStateReaderTest, 
TestFastWriter, LeaderFailureAfterFreshStartTest, TestBlendedInfixSuggestions, 
TestManagedSchemaAPI, TestXmlQParserPlugin, TestSuggestSpellingConverter, 
AnalysisAfterCoreReloadTest, StatelessScriptUpdateProcessorFactoryTest, 
TestCloudPseudoReturnFields, CdcrReplicationDistributedZkTest, 
TestPullReplicaErrorHandling, ClassificationUpdateProcessorFactoryTest, 
TestLuceneIndexBackCompat, PKIAuthenticationIntegrationTest, 
PingRequestHandlerTest, TestPartialUpdateDeduplication, TestSolrCoreSnapshots, 
DistributedExpandComponentTest, TestManagedSynonymGraphFilterFactory, 
BasicAuthIntegrationTest, GraphQueryTest, TestCharFilters, HdfsThreadLeakTest, 
TestUseDocValuesAsStored2, TestRequestStatusCollectionAPI, 
TestDistributedMissingSort, SolrJmxReporterCloudTest, TestDistributedGrouping, 
StressHdfsTest, TestClassicSimilarityFactory, TestHdfsBackupRestoreCore, 
PolyFieldTest, SolrGangliaReporterTest, TestSolrIndexConfig, TestCoreContainer, 
TestSimpleTrackingShardHandler, TestCrossCoreJoin, 
TestPayloadCheckQParserPlugin, LoggingHandlerTest, HdfsDirectoryFactoryTest, 
TestValueSourceCache, TestSmileRequest, TestSolrCloudWithSecureImpersonation, 
TestIntervalFaceting, TestBackupRepositoryFactory, TestNamedUpdateProcessors, 
CoreAdminHandlerTest, ZkNodePropsTest, CoreAdminCreateDiscoverTest, 
TestCustomSort, TestSegmentSorting, TestLRUCache, TestSchemaSimilarityResource, 
DocumentBuilderTest, ConcurrentDeleteAndCreateCollectionTest, TestStressLucene, 
TestCloudSearcherWarming, UninvertDocValuesMergePolicyTest, BJQParserTest, 
DistributedFacetPivotWhiteBoxTest, TestImplicitCoreProperties, 
TestScoreJoinQPScore, TestSystemIdResolver, MetricsHandlerTest, CopyFieldTest, 
AnalyticsQueryTest, TestTrieFacet, TestSolrXml, 
HdfsCollectionsAPIDistributedZkTest, TestCSVLoader, TestCollectionAPI, 
TestSerializedLuceneMatchVersion, SystemInfoHandlerTest, SolrShardReporterTest, 
TestNumericRangeQuery32, TestPKIAuthenticationPlugin, 
LeaderElectionIntegrationTest, ZkSolrClientTest, SolrMetricReporterTest, 
DocValuesMissingTest, BlockCacheTest, MoveReplicaHDFSFailoverTest, 
TestFieldCacheSort, TestPrepRecovery, TermVectorComponentDistributedTest, 
RollingRestartTest, BadComponentTest, TestReload, TestBulkSchemaAPI, 
TestTlogReplica, HdfsRecoverLeaseTest, TestLegacyNumericRangeQueryBuilder, 
CoreMergeIndexesAdminHandlerTest, TolerantUpdateProcessorTest, BufferStoreTest, 
MigrateRouteKeyTest, TestRecoveryHdfs, TestFieldCollectionResource, 
TestMacroExpander, TestTolerantUpdateProcessorRandomCloud, 
HdfsBasicDistributedZk2Test, TestEmbeddedSolrServerConstructors, 
TestCollationField, TestHashPartitioner, TestQueryWrapperFilter, 
TestLuceneMatchVersion, TestJettySolrRunner, 
BigEndianAscendingWordSerializerTest, TestExactStatsCache, 
TestNonDefinedSimilarityFactory, TestFieldCache, TestPostingsSolrHighlighter, 
DeleteLastCustomShardedReplicaTest, TestSchemalessBufferedUpdates, 
SolrCoreCheckLockOnStartupTest, NodeMutatorTest, TestExpandComponent, 
TestCloudJSONFacetJoinDomain, SynonymTokenizerTest, TestNumericTokenStream, 
ClassificationUpdateProcessorTest, QueryElevationComponentTest, 
CloudMLTQParserTest, NodeLostTriggerTest, CollectionsAPIAsyncDistributedZkTest, 
TriggerIntegrationTest]
   [junit4] Completed [315/752 (1!)] on J1 in 180.97s, 13 tests, 1 failure <<< 
FAILURES!

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

Reply via email to