Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1101/ Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed. FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeMarkersRegistration Error Message: Path /autoscaling/nodeAdded/127.0.0.1:36645_solr wasn't created Stack Trace: java.lang.AssertionError: Path /autoscaling/nodeAdded/127.0.0.1:36645_solr wasn't created at __randomizedtesting.SeedInfo.seed([999AE2567DAB0BB6:81206A5A739EC659]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeMarkersRegistration(TriggerIntegrationTest.java:936) 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 13736 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest [junit4] 2> 2256617 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/init-core-data-001 [junit4] 2> 2256618 WARN (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=21 numCloses=21 [junit4] 2> 2256618 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 2256620 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 2256621 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001 [junit4] 2> 2256621 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2256621 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2256621 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2256623 ERROR (Thread-7673) [ ] 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> 2256721 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33871 [junit4] 2> 2256723 INFO (zkConnectionManagerCallback-7976-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256729 INFO (jetty-launcher-7973-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2256758 INFO (jetty-launcher-7973-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2256759 INFO (jetty-launcher-7973-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6be54420{/solr,null,AVAILABLE} [junit4] 2> 2256759 INFO (jetty-launcher-7973-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6cbd0135{/solr,null,AVAILABLE} [junit4] 2> 2256760 INFO (jetty-launcher-7973-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d854857{SSL,[ssl, http/1.1]}{127.0.0.1:34279} [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ] o.e.j.s.Server Started @2258128ms [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7d1470d0{SSL,[ssl, http/1.1]}{127.0.0.1:42069} [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34279} [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ] o.e.j.s.Server Started @2258128ms [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42069} [junit4] 2> 2256761 ERROR (jetty-launcher-7973-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2256761 ERROR (jetty-launcher-7973-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T11:07:14.365Z [junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T11:07:14.365Z [junit4] 2> 2256763 INFO (zkConnectionManagerCallback-7980-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256764 INFO (zkConnectionManagerCallback-7979-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256764 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2256764 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2256772 INFO (jetty-launcher-7973-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr [junit4] 2> 2256772 INFO (jetty-launcher-7973-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr [junit4] 2> 2256773 INFO (zkConnectionManagerCallback-7986-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256773 INFO (zkConnectionManagerCallback-7988-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256774 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 0x160b68dcbb10004, 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> 2256774 INFO (zkConnectionManagerCallback-7991-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256774 INFO (zkConnectionManagerCallback-7992-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42069_solr [junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34279_solr [junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer (id=99279911926169605-127.0.0.1:42069_solr-n_0000000000) starting [junit4] 2> 2256799 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2256799 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2256801 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 2256802 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42069_solr [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:34279_solr] [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 2256802 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2256802 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2256802 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 2256803 DEBUG (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2256844 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42069.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256845 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34279.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42069.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42069.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34279.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34279.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node1/. [junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node2/. [junit4] 2> 2256872 INFO (zkConnectionManagerCallback-7998-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256874 INFO (zkConnectionManagerCallback-8002-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256874 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2256875 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33871/solr ready [junit4] 2> 2256881 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState [junit4] 2> 2256881 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2 [junit4] 2> 2256882 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 2256882 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 2256883 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2256883 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2256883 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 2256884 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2256884 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7ffd6024{/solr,null,AVAILABLE} [junit4] 2> 2256884 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@45f1ebce{SSL,[ssl, http/1.1]}{127.0.0.1:43859} [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server Started @2258252ms [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43859} [junit4] 2> 2256885 ERROR (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2256885 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T11:07:14.488Z [junit4] 2> 2256886 INFO (zkConnectionManagerCallback-8004-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256886 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2256903 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr [junit4] 2> 2256904 INFO (zkConnectionManagerCallback-8008-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256905 INFO (zkConnectionManagerCallback-8010-thread-1-processing-n:127.0.0.1:43859_solr) [n:127.0.0.1:43859_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2256908 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2256909 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2256909 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43859_solr [junit4] 2> 2256910 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2256910 INFO (zkCallback-8009-thread-1-processing-n:127.0.0.1:43859_solr) [n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2256913 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2256913 INFO (zkCallback-8001-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2256952 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43859.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256957 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43859.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256957 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43859.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2256958 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:43859_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node3/. [junit4] 2> 2257013 INFO (qtp524086121-29985) [n:127.0.0.1:34279_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> 2257015 INFO (qtp1653336593-30001) [n:127.0.0.1:42069_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> 2257031 INFO (qtp269752659-30045) [n:127.0.0.1:43859_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> 2257031 DEBUG (qtp1653336593-29993) [n:127.0.0.1:42069_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2257031 INFO (qtp1653336593-29993) [n:127.0.0.1:42069_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=34 [junit4] 2> 2257031 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 2257032 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:42069_solr, 127.0.0.1:43859_solr, 127.0.0.1:34279_solr] [junit4] 2> 2257032 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 2257032 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@45f1ebce{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 2257032 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=980382025 [junit4] 2> 2257032 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 2257032 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7b137207: rootName = solr_43859, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@74433e0d [junit4] 2> 2257032 INFO (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2257033 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2257033 DEBUG (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 3 [junit4] 2> 2257033 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 2257037 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 2257037 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1c3d54b1: rootName = solr_43859, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@13133f0 [junit4] 2> 2257040 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 2257040 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@467bfd1b: rootName = solr_43859, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4b15606 [junit4] 2> 2257041 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:43859_solr [junit4] 2> 2257041 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 2257041 INFO (zkCallback-8009-thread-1-processing-n:127.0.0.1:43859_solr) [n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2257041 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2257041 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2257041 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2257041 INFO (zkCallback-8001-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2257041 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7ffd6024{/solr,null,UNAVAILABLE} [junit4] 2> 2258034 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 2258034 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:43859_solr [junit4] 2> 2258544 INFO (qtp524086121-29991) [n:127.0.0.1:34279_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> 2258545 INFO (qtp1653336593-29995) [n:127.0.0.1:42069_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> 2258545 DEBUG (qtp1653336593-29999) [n:127.0.0.1:42069_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2258546 INFO (qtp1653336593-29999) [n:127.0.0.1:42069_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 2258546 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 2258547 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:42069_solr, 127.0.0.1:34279_solr] [junit4] 2> 2258547 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 2258547 INFO (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2258548 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:43859_solr [junit4] 2> 2258549 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_restore_trigger with currently live nodes: 2 [junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:43859_solr] [junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"935c111305629Tajxqea3gpnxlbq48kuywanoea", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":2592378123736617, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592378123736617], [junit4] 2> "nodeNames":["127.0.0.1:43859_solr"]}} [junit4] 2> 2258549 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 2258550 INFO (ScheduledTrigger-8227-thread-1) [n:127.0.0.1:42069_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2258550 DEBUG (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"935c111305629Tajxqea3gpnxlbq48kuywanoea", [junit4] 2> "source":"node_lost_restore_trigger", [junit4] 2> "eventTime":2592378123736617, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592378123736617], [junit4] 2> "_enqueue_time_":2592378124912904, [junit4] 2> "nodeNames":["127.0.0.1:43859_solr"]}} [junit4] 2> 2258551 INFO (TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState [junit4] 2> 2258552 DEBUG (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=935c111305629Tajxqea3gpnxlbq48kuywanoea [junit4] 2> 2258568 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEventQueue [junit4] 2> 2258569 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5 [junit4] 2> 2258569 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 2258569 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 2258570 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2258570 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2258571 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 2258573 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2258579 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=5 [junit4] 2> 2258581 INFO (qtp524086121-29990) [n:127.0.0.1:34279_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> 2258581 INFO (qtp1653336593-30001) [n:127.0.0.1:42069_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> 2258581 DEBUG (qtp1653336593-30000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2258582 INFO (qtp1653336593-30000) [n:127.0.0.1:42069_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=2 [junit4] 2> 2258582 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 2258582 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventQueueAction instantiated [junit4] 2> 2258583 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:42069_solr, 127.0.0.1:34279_solr] [junit4] 2> 2258583 DEBUG (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}], enabled=true} [junit4] 2> 2258583 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 2258584 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2258585 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2258585 DEBUG (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 2258585 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2258585 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2258586 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2258589 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@650a44f2{/solr,null,AVAILABLE} [junit4] 2> 2258590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@da1f34d{SSL,[ssl, http/1.1]}{127.0.0.1:41701} [junit4] 2> 2258590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server Started @2259957ms [junit4] 2> 2258590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41701} [junit4] 2> 2258590 ERROR (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2258590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2258590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2258591 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2258591 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T11:07:16.194Z [junit4] 2> 2258593 INFO (zkConnectionManagerCallback-8014-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2258594 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2258604 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr [junit4] 2> 2258605 INFO (zkConnectionManagerCallback-8018-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2258608 INFO (zkConnectionManagerCallback-8020-thread-1-processing-n:127.0.0.1:41701_solr) [n:127.0.0.1:41701_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2258613 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2258615 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2258616 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41701_solr [junit4] 2> 2258617 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2258617 INFO (zkCallback-8001-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2258617 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2258617 INFO (zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr) [n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2258675 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41701.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2258681 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41701.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2258681 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41701.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2258682 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:41701_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node4/. [junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:41701_solr at time 2592379161614893 [junit4] 2> 2260577 INFO (OverseerCollectionConfigSetProcessor-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:41701_solr] added at times [2592379161614893], now=2592380162841182 [junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}} [junit4] 2> 2260588 INFO (ScheduledTrigger-8227-thread-2) [n:127.0.0.1:42069_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2260589 DEBUG (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "_enqueue_time_":2592380163157100, [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}} [junit4] 2> 2260589 INFO (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "_enqueue_time_":2592380163157100, [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}} [junit4] 2> 2260590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7d1470d0{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 2260590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2029564889 [junit4] 2> 2260590 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 2260591 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@11581c65: rootName = solr_42069, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@100380e [junit4] 2> 2260600 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 2260600 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@69d9c5c6: rootName = solr_42069, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@13133f0 [junit4] 2> 2260606 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 2260606 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@423b34d8: rootName = solr_42069, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@4b15606 [junit4] 2> 2260608 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:42069_solr [junit4] 2> 2260609 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 2260609 INFO (zkCallback-8001-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2260609 INFO (zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr) [n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2260609 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2260609 INFO (zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2260609 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 2260609 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.Overseer Overseer (id=99279911926169605-127.0.0.1:42069_solr-n_0000000000) closing [junit4] 2> 2260610 INFO (OverseerStateUpdate-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:42069_solr [junit4] 2> 2260610 WARN (OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000) [n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 2260610 DEBUG (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 2260610 WARN (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers Exception executing actions [junit4] 2> org.apache.lucene.store.AlreadyClosedException: ScheduledTrigger node_added_trigger1 has been closed. [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.dequeue(ScheduledTriggers.java:525) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:337) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] 2> at java.lang.Thread.run(Thread.java:748) [junit4] 2> 2260611 DEBUG (AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr) [n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 22 ms for event id=935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec [junit4] 2> 2260635 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6cbd0135{/solr,null,UNAVAILABLE} [junit4] 2> 2260635 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34279_solr [junit4] 2> 2260636 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.Overseer Overseer (id=99279911926169606-127.0.0.1:34279_solr-n_0000000001) starting [junit4] 2> 2260640 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 2260641 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 2260641 INFO (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventQueueAction instantiated [junit4] 2> 2260641 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2260642 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}], enabled=true} [junit4] 2> 2260642 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2260642 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion -1 [junit4] 2> 2260642 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 2260643 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2260644 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2260644 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 2260644 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "_dequeue_time_":2592380219582429, [junit4] 2> "_enqueue_time_":2592380163157100, [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 2260644 INFO (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2260645 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "_dequeue_time_":2592380219582429, [junit4] 2> "_enqueue_time_":2592380163157100, [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 2260645 INFO (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: { [junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592379161614893, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592379161614893], [junit4] 2> "_dequeue_time_":2592380219582429, [junit4] 2> "_enqueue_time_":2592380163157100, [junit4] 2> "nodeNames":["127.0.0.1:41701_solr"], [junit4] 2> "replaying":true}} [junit4] 2> 2260645 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2260645 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2260646 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec [junit4] 2> 2261644 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2261646 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2261646 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2262645 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2262647 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2262647 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2263645 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2263647 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2263647 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2264645 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2264647 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2264647 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2265636 INFO (TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEventQueue [junit4] 2> 2265642 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling [junit4] 2> 2265643 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 8 [junit4] 2> 2265643 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 2265643 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 2265643 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2265643 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2265644 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 2265647 INFO (qtp524086121-29986) [n:127.0.0.1:34279_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> 2265664 INFO (qtp1580809983-30078) [n:127.0.0.1:41701_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> 2265664 DEBUG (qtp524086121-29991) [n:127.0.0.1:34279_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2265665 INFO (qtp524086121-29991) [n:127.0.0.1:34279_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=19 [junit4] 2> 2265665 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 2265665 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2265665 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_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> 2265665 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9 [junit4] 2> 2265666 INFO (qtp524086121-29987) [n:127.0.0.1:34279_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> 2265666 INFO (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2265666 INFO (qtp1580809983-30083) [n:127.0.0.1:41701_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> 2265666 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2265667 DEBUG (qtp524086121-29990) [n:127.0.0.1:34279_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2265667 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9 [junit4] 2> 2265667 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2265667 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2265667 INFO (qtp524086121-29990) [n:127.0.0.1:34279_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=1 [junit4] 2> 2265667 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 2265667 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2265667 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_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> 2265667 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2265667 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_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> 2265667 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 2265668 INFO (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2265668 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2265668 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 2265668 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2265668 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2265668 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 2265669 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6c3ce994{/solr,null,AVAILABLE} [junit4] 2> 2265669 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@397e370f{SSL,[ssl, http/1.1]}{127.0.0.1:35953} [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.e.j.s.Server Started @2267037ms [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35953} [junit4] 2> 2265670 ERROR (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2265670 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-02T11:07:23.273Z [junit4] 2> 2265671 INFO (zkConnectionManagerCallback-8024-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2265671 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2265675 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr [junit4] 2> 2265676 INFO (zkConnectionManagerCallback-8028-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2265677 INFO (zkConnectionManagerCallback-8030-thread-1-processing-n:127.0.0.1:35953_solr) [n:127.0.0.1:35953_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2265678 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2265679 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2265679 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35953_solr [junit4] 2> 2265680 INFO (zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr) [n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2265680 INFO (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2265680 INFO (zkCallback-8001-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2265680 INFO (zkCallback-8029-thread-1-processing-n:127.0.0.1:35953_solr) [n:127.0.0.1:35953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2265716 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35953.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2265722 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35953.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2265723 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35953.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246 [junit4] 2> 2265723 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [n:127.0.0.1:35953_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node5/. [junit4] 2> 2266667 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:35953_solr at time 2592386243233988 [junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592386243233988], now=2592386243315937 [junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"935c2f52608c4Tajxqea3gpnxlbq48kuywanoef", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592386243233988, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592386243233988], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2266669 INFO (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2266669 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"935c2f52608c4Tajxqea3gpnxlbq48kuywanoef", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":2592386243233988, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592386243233988], [junit4] 2> "_enqueue_time_":2592386243541197, [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2266669 INFO (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger1 [junit4] 2> 2266671 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=935c2f52608c4Tajxqea3gpnxlbq48kuywanoef [junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:35953_solr at time 2592387244772636 [junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592387244772636], now=2592387244845377 [junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoeh", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2267670 INFO (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2267671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2267671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592387244772636], now=2592388246323729 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoej", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592387244772636], now=2592389246831764 [junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoek", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2270671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2270671 DEBUG (ScheduledTrigger-8249-thread-1) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592387244772636], now=2592390247296109 [junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoel", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-4) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:35953_solr] added at times [2592387244772636], now=2592391247809781 [junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoem", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2271673 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoem", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":2592387244772636, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[2592387244772636], [junit4] 2> "_enqueue_time_":2592391248118994, [junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}} [junit4] 2> 2271673 INFO (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest last action at 1514891244272000000 current time = 1514891249276000000 [junit4] 2> real diff: 5004000000 [junit4] 2> min diff: 4998000000 [junit4] 2> 2271674 INFO (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger2 [junit4] 2> 2271674 DEBUG (AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=935c330d84d1cTajxqea3gpnxlbq48kuywanoem [junit4] 2> 2271677 INFO (qtp524086121-29986) [n:127.0.0.1:34279_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> 2271720 INFO (qtp1114245096-30113) [n:127.0.0.1:35953_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> 2271722 INFO (qtp1580809983-30084) [n:127.0.0.1:41701_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> 2271722 DEBUG (qtp524086121-29985) [n:127.0.0.1:34279_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2271723 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=47 [junit4] 2> 2271723 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 11 [junit4] 2> 2271724 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2271724 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_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> 2271724 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2271725 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr] [junit4] 2> 2271725 DEBUG (zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr) [n:127.0.0.1:34279_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> 2271725 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 11 [junit4] 2> 2271725 INFO (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001) [n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2271726 DEBUG (OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1: [...truncated too long message...] -thread-1) [n:127.0.0.1:43373_solr c:testMetricTrigger s:shard2 r:core_node4 x:testMetricTrigger_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testMetricTrigger.shard2.leader, tag=1121638154 [junit4] 2> 2411640 INFO (zkCallback-8079-thread-3-processing-n:127.0.0.1:43373_solr) [n:127.0.0.1:43373_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43373_solr [junit4] 2> 2411640 INFO (jetty-closer-7974-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@748df9f5{/solr,null,UNAVAILABLE} [junit4] 2> 2411640 INFO (jetty-closer-7974-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@31d9fa66{/solr,null,UNAVAILABLE} [junit4] 2> 2411640 WARN (zkCallback-8112-thread-3-processing-n:127.0.0.1:35603_solr) [n:127.0.0.1:35603_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2411640 INFO (jetty-closer-7974-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@cd58e77{/solr,null,UNAVAILABLE} [junit4] 2> 2411640 INFO (jetty-closer-7974-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@46ad49e0{/solr,null,UNAVAILABLE} [junit4] 2> 2413140 WARN (zkCallback-8132-thread-3-processing-n:127.0.0.1:37617_solr) [n:127.0.0.1:37617_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2413140 WARN (zkCallback-8172-thread-2-processing-n:127.0.0.1:36345_solr) [n:127.0.0.1:36345_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 2413140 INFO (jetty-closer-7974-thread-8) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5e3e043e{/solr,null,UNAVAILABLE} [junit4] 2> 2413140 INFO (jetty-closer-7974-thread-11) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@664473c7{/solr,null,UNAVAILABLE} [junit4] 2> 2413141 ERROR (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-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> 2413141 INFO (SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33871 33871 [junit4] 2> 2418203 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33871 33871 [junit4] 2> 2418204 WARN (Thread-7673) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 20 /solr/aliases.json [junit4] 2> 19 /solr/security.json [junit4] 2> 3 /solr/configs/conf [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 25 /solr/collections/testMetricTrigger/state.json [junit4] 2> 20 /solr/clusterprops.json [junit4] 2> 20 /solr/clusterstate.json [junit4] 2> 5 /solr/autoscaling.json [junit4] 2> 2 /solr/overseer_elect/election/99279911926169651-127.0.0.1:39477_solr-n_0000000015 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169614-127.0.0.1:41701_solr-n_0000000003 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169606-127.0.0.1:34279_solr-n_0000000001 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169642-127.0.0.1:35603_solr-n_0000000012 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169654-127.0.0.1:41141_solr-n_0000000016 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169623-127.0.0.1:36645_solr-n_0000000006 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169635-127.0.0.1:42793_solr-n_0000000010 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169626-127.0.0.1:42821_solr-n_0000000007 [junit4] 2> 2 /solr/overseer_elect/election/99279911926169648-127.0.0.1:37617_solr-n_0000000014 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 20 /solr/live_nodes [junit4] 2> 20 /solr/collections [junit4] 2> 5 /solr/overseer/queue-work [junit4] 2> 5 /solr/autoscaling/events/.auto_add_replicas [junit4] 2> 5 /solr/overseer/queue [junit4] 2> 5 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/autoscaling/events/node_added_trigger [junit4] 2> 2 /solr/autoscaling/events/node_added_trigger1 [junit4] 2> 2 /solr/autoscaling/events/node_lost_trigger [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=BlockTreeOrds(blocksize=128), x_s=PostingsFormat(name=Asserting)}, docValues:{}, maxPointsInLeafNode=1806, maxMBSortInHeap=7.6907611988713445, sim=RandomSimilarity(queryNorm=false): {}, locale=ms-MY, timezone=America/Swift_Current [junit4] 2> NOTE: Linux 4.10.0-40-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=8,threads=1,free=209973408,total=518979584 [junit4] 2> NOTE: All tests run in this JVM: [TestClassicSimilarityFactory, TestFileDictionaryLookup, LargeFieldTest, TestLRUCache, TestCoreDiscovery, TestSchemaNameResource, TestDynamicLoading, IndexSchemaTest, TestImpersonationWithHadoopAuth, IndexBasedSpellCheckerTest, TestExtendedDismaxParser, TestConfigReload, LeaderInitiatedRecoveryOnCommitTest, FileBasedSpellCheckerTest, TestHashPartitioner, TestMiniSolrCloudClusterSSL, UninvertDocValuesMergePolicyTest, TestHdfsUpdateLog, TestComputePlanAction, TestQuerySenderListener, TestSchemalessBufferedUpdates, MoveReplicaHDFSTest, TestCSVResponseWriter, ReplicationFactorTest, TestExportWriter, RecoveryAfterSoftCommitTest, TestRequestForwarding, TestFieldCache, SmileWriterTest, DefaultValueUpdateProcessorTest, TimeZoneUtilsTest, PluginInfoTest, CdcrUpdateLogTest, TestRealTimeGet, TestStressLiveNodes, TestNestedDocsSort, SegmentsInfoRequestHandlerTest, TestManagedSchemaThreadSafety, TestSkipOverseerOperations, TestHdfsCloudBackupRestore, SolrJmxReporterTest, TestCollectionsAPIViaSolrCloudCluster, TestNumericRangeQuery64, RecoveryZkTest, BasicDistributedZk2Test, TestLegacyField, UpdateLogTest, UnloadDistributedZkTest, TestRestManager, HdfsCollectionsAPIDistributedZkTest, TestCoreContainer, AsyncCallRequestStatusResponseTest, LoggingHandlerTest, TestDistributedMissingSort, TestInitParams, CollectionReloadTest, SolrTestCaseJ4Test, TestEmbeddedSolrServerConstructors, CoreAdminRequestStatusTest, SolrMetricManagerTest, TestRawTransformer, AnalyticsMergeStrategyTest, TestFunctionQuery, V2StandaloneTest, SuggesterTest, TestQueryTypes, TestTolerantSearch, ChaosMonkeyNothingIsSafeTest, ReturnFieldsTest, TestLegacyTerms, RequestLoggingTest, TestReloadDeadlock, TestTriggerIntegration, DirectSolrSpellCheckerTest, TestConfigOverlay, TestSubQueryTransformerDistrib, AlternateDirectoryTest, BlockJoinFacetSimpleTest, TestJavabinTupleStreamParser, MigrateRouteKeyTest, TestFieldCacheSortRandom, MetricUtilsTest, UniqFieldsUpdateProcessorFactoryTest, TestShardHandlerFactory, WordBreakSolrSpellCheckerTest, SuggesterWFSTTest, TestComplexPhraseLeadingWildcard, CoreAdminHandlerTest, TestDynamicFieldCollectionResource, TestFieldSortValues, OverseerTest, SolrGangliaReporterTest, LeaderElectionTest, TestFuzzyAnalyzedSuggestions, HighlighterTest, HdfsDirectoryFactoryTest, ClassificationUpdateProcessorIntegrationTest, ConfigSetsAPITest, SolrCoreCheckLockOnStartupTest, CdcrBootstrapTest, TestSolrDeletionPolicy2, TestSearchPerf, RuleEngineTest, HttpTriggerListenerTest, TestPayloadScoreQParserPlugin, PKIAuthenticationIntegrationTest, MetricsHandlerTest, SystemInfoHandlerTest, TestReplicationHandlerBackup, TestCharFilters, ZkNodePropsTest, TestSchemaVersionResource, TestLegacyFieldCache, TestNamedUpdateProcessors, AtomicUpdateProcessorFactoryTest, TestPullReplica, QueryElevationComponentTest, TriLevelCompositeIdRoutingTest, HighlighterMaxOffsetTest, SolrShardReporterTest, TestChildDocTransformer, TestDistributedGrouping, OpenCloseCoreStressTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, TestZkChroot, ZkCLITest, SimplePostToolTest, SpellCheckCollatorTest, DocValuesTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, TestRemoteStreaming, DistanceFunctionTest, SolrInfoBeanTest, DebugComponentTest, DisMaxRequestHandlerTest, TestWriterPerf, PrimitiveFieldTypeTest, TermsComponentTest, TestValueSourceCache, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, TestAnalyzedSuggestions, CSVRequestHandlerTest, TestComponentsName, TestLFUCache, TestBinaryField, MinimalSchemaTest, TestSolrCoreProperties, DirectSolrConnectionTest, TestLuceneMatchVersion, TestXIncludeConfig, TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory, TestIBSimilarityFactory, ScriptEngineTest, PrimUtilsTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, SliceStateTest, FileUtilsTest, CursorPagingTest, TestCursorMarkWithoutUniqueKey, TestEmbeddedSolrServerAdminHandler, TestEmbeddedSolrServerSchemaAPI, TestJettySolrRunner, ConnectionReuseTest, AssignBackwardCompatibilityTest, CollectionsAPISolrJTest, DeleteShardTest, DistributedQueueTest, HttpPartitionTest, RemoteQueryErrorTest, RestartWhileUpdatingTest, SSLMigrationTest, SaslZkACLProviderTest, ShardSplitTest, TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorRandomCloud, AutoAddReplicasIntegrationTest, TriggerIntegrationTest] [junit4] Completed [627/764 (1!)] on J2 in 161.67s, 14 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 48606 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org