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