Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1278/ Java: 32bit/jdk1.8.0_144 -client -XX:+UseSerialGC
2 tests failed. FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTriggerRestoreState Error Message: The trigger did not fire at all Stack Trace: java.lang.AssertionError: The trigger did not fire at all at __randomizedtesting.SeedInfo.seed([F8655AEAAE497F5A:D39A8FB134316A8A]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTriggerRestoreState(TriggerIntegrationTest.java:368) 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) FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger Error Message: Stack Trace: java.lang.NullPointerException at __randomizedtesting.SeedInfo.seed([F8655AEAAE497F5A:42696D65F1A1A915]:0) at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1565) 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 13821 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest [junit4] 2> 2979682 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-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/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/init-core-data-001 [junit4] 2> 2979682 WARN (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24 [junit4] 2> 2979682 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 2979684 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN) [junit4] 2> 2979685 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-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/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001 [junit4] 2> 2979685 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2979685 INFO (Thread-5589) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2979685 INFO (Thread-5589) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2979687 ERROR (Thread-5589) [ ] 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> 2979785 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37235 [junit4] 2> 2979788 INFO (zkConnectionManagerCallback-4554-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979794 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:27:37+05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2979794 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:27:37+05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2979794 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2979794 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2979794 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 2979795 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2979795 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2979795 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.session Scavenging every 660000ms [junit4] 2> 2979795 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1d5abad{/solr,null,AVAILABLE} [junit4] 2> 2979795 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1a3d59c{/solr,null,AVAILABLE} [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@8281ba{SSL,[ssl, http/1.1]}{127.0.0.1:40773} [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@b3e7ee{SSL,[ssl, http/1.1]}{127.0.0.1:39799} [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-1) [ ] o.e.j.s.Server Started @2981072ms [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-2) [ ] o.e.j.s.Server Started @2981073ms [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40773} [junit4] 2> 2979796 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39799} [junit4] 2> 2979797 ERROR (jetty-launcher-4551-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2979797 ERROR (jetty-launcher-4551-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-02T02:17:29.026Z [junit4] 2> 2979797 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-02T02:17:29.026Z [junit4] 2> 2979798 INFO (zkConnectionManagerCallback-4557-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979799 INFO (zkConnectionManagerCallback-4558-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979799 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2979799 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2979810 INFO (jetty-launcher-4551-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37235/solr [junit4] 2> 2979810 INFO (jetty-launcher-4551-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37235/solr [junit4] 2> 2979811 INFO (zkConnectionManagerCallback-4564-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979811 INFO (zkConnectionManagerCallback-4566-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979813 INFO (zkConnectionManagerCallback-4568-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979813 INFO (zkConnectionManagerCallback-4570-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2979882 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2979882 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2979883 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40773_solr [junit4] 2> 2979883 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39799_solr [junit4] 2> 2979883 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.Overseer Overseer (id=72077320986820613-127.0.0.1:40773_solr-n_0000000000) starting [junit4] 2> 2979884 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2979884 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2979888 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 2979889 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 2979889 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40773_solr [junit4] 2> 2979889 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:39799_solr] [junit4] 2> 2979889 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 2979889 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 2979890 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2979890 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2979890 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2979891 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 2979891 DEBUG (ScheduledTrigger-8396-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 2980048 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39799.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980060 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39799.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980060 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39799.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980062 INFO (jetty-launcher-4551-thread-2) [n:127.0.0.1:39799_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001/node2/. [junit4] 2> 2980079 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40773.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980091 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40773.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980092 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40773.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980094 INFO (jetty-launcher-4551-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001/node1/. [junit4] 2> 2980121 INFO (zkConnectionManagerCallback-4576-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2980124 INFO (zkConnectionManagerCallback-4580-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2980125 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2980125 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37235/solr ready [junit4] 2> 2980145 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testListeners [junit4] 2> 2980145 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2 [junit4] 2> 2980145 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 2980145 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 2980147 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2980147 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2980147 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 2980301 INFO (qtp21722514-22234) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980305 INFO (qtp501413-22227) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980306 DEBUG (qtp501413-22235) [n:127.0.0.1:40773_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2980307 INFO (qtp501413-22235) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=73 [junit4] 2> 2980307 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 2980308 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:39799_solr] [junit4] 2> 2980308 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}], enabled=true} [junit4] 2> 2980308 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 2980309 INFO (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2980310 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2980310 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 2980310 DEBUG (ScheduledTrigger-8396-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2980310 DEBUG (ScheduledTrigger-8396-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 2980314 INFO (qtp21722514-22238) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980316 INFO (qtp501413-22237) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980317 DEBUG (qtp501413-22239) [n:127.0.0.1:40773_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2980318 INFO (qtp501413-22239) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=6 [junit4] 2> 2980318 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 2980318 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:39799_solr] [junit4] 2> 2980318 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}], enabled=true} [junit4] 2> 2980318 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 2980319 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2980319 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4 [junit4] 2> 2980320 INFO (qtp21722514-22234) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980322 INFO (qtp501413-22227) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2980322 DEBUG (qtp501413-22235) [n:127.0.0.1:40773_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2980323 INFO (qtp501413-22235) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 2980323 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 2980323 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:39799_solr] [junit4] 2> 2980323 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}, {name=test1, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}], enabled=true} [junit4] 2> 2980323 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 2980324 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2980324 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 2980324 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:27:37+05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2980325 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2980325 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2980325 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session Scavenging every 660000ms [junit4] 2> 2980325 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1de0364{/solr,null,AVAILABLE} [junit4] 2> 2980326 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1fb6bf3{SSL,[ssl, http/1.1]}{127.0.0.1:44791} [junit4] 2> 2980326 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server Started @2981602ms [junit4] 2> 2980326 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44791} [junit4] 2> 2980326 ERROR (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2980327 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2980327 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2980327 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2980327 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-02T02:17:29.556Z [junit4] 2> 2980328 INFO (zkConnectionManagerCallback-4582-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2980329 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2980338 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37235/solr [junit4] 2> 2980340 INFO (zkConnectionManagerCallback-4586-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2980342 INFO (zkConnectionManagerCallback-4588-thread-1-processing-n:127.0.0.1:44791_solr) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2980346 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2980347 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2980348 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44791_solr [junit4] 2> 2980349 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2980349 INFO (zkCallback-4579-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2980350 INFO (zkCallback-4587-thread-1-processing-n:127.0.0.1:44791_solr) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2980353 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2980560 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44791.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980577 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44791.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980578 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44791.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2980580 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:44791_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001/node3/. [junit4] 2> 2981311 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2981312 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2981312 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:44791_solr at time 301010978670417 [junit4] 2> 2982313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2982313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2983313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2983313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2984313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2984313 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 2984314 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerL firing registered processor for nodes: [127.0.0.1:44791_solr] added at times [301010978670417], now=301013980464993 [junit4] 2> 2984314 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"111c494750751Tchxzysxhzwvurkxji6mquff32", [junit4] 2> "source":"node_added_triggerL", [junit4] 2> "eventTime":301010978670417, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301010978670417], [junit4] 2> "nodeNames":["127.0.0.1:44791_solr"]}} [junit4] 2> 2984314 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_triggerL] [junit4] 2> 2984315 INFO (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2984316 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"111c494750751Tchxzysxhzwvurkxji6mquff32", [junit4] 2> "source":"node_added_triggerL", [junit4] 2> "eventTime":301010978670417, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301010978670417], [junit4] 2> "_enqueue_time_":301013981134342, [junit4] 2> "nodeNames":["127.0.0.1:44791_solr"]}} [junit4] 2> 2984317 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerL after 5000ms [junit4] 2> 2984317 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=111c494750751Tchxzysxhzwvurkxji6mquff32 [junit4] 2> 2986319 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:27:37+05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2986320 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2986320 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2986320 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 2986321 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1f504c9{/solr,null,AVAILABLE} [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@271950{SSL,[ssl, http/1.1]}{127.0.0.1:37049} [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server Started @2987598ms [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=37049} [junit4] 2> 2986322 ERROR (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2986322 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-02T02:17:35.551Z [junit4] 2> 2986324 INFO (zkConnectionManagerCallback-4592-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2986325 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2986338 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37235/solr [junit4] 2> 2986339 INFO (zkConnectionManagerCallback-4596-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2986342 INFO (zkConnectionManagerCallback-4598-thread-1-processing-n:127.0.0.1:37049_solr) [n:127.0.0.1:37049_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2986345 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3) [junit4] 2> 2986346 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2986348 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37049_solr [junit4] 2> 2986349 INFO (zkCallback-4579-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2986349 INFO (zkCallback-4587-thread-1-processing-n:127.0.0.1:44791_solr) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2986349 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2986349 INFO (zkCallback-4597-thread-1-processing-n:127.0.0.1:37049_solr) [n:127.0.0.1:37049_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2986349 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2986594 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37049.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2986606 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37049.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2986606 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_37049.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2986608 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:37049_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001/node4/. [junit4] 2> 2989317 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2989318 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2989318 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:37049_solr at time 301018984598439 [junit4] 2> 2990319 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2990319 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2991319 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2991319 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2992320 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerL [junit4] 2> 2992320 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2992320 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerL firing registered processor for nodes: [127.0.0.1:37049_solr] added at times [301018984598439], now=301021986642131 [junit4] 2> 2992320 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"111c671a5cba7Tchxzysxhzwvurkxji6mquff34", [junit4] 2> "source":"node_added_triggerL", [junit4] 2> "eventTime":301018984598439, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301018984598439], [junit4] 2> "nodeNames":["127.0.0.1:37049_solr"]}} [junit4] 2> 2992320 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_triggerL] [junit4] 2> 2992321 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"111c671a5cba7Tchxzysxhzwvurkxji6mquff34", [junit4] 2> "source":"node_added_triggerL", [junit4] 2> "eventTime":301018984598439, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301018984598439], [junit4] 2> "_enqueue_time_":301021986893173, [junit4] 2> "nodeNames":["127.0.0.1:37049_solr"]}} [junit4] 2> 2992321 WARN (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Exception executing actions [junit4] 2> java.lang.Exception: Error executing action: test1 for trigger event: { [junit4] 2> "id":"111c671a5cba7Tchxzysxhzwvurkxji6mquff34", [junit4] 2> "source":"node_added_triggerL", [junit4] 2> "eventTime":301018984598439, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301018984598439], [junit4] 2> "_enqueue_time_":301021986893173, [junit4] 2> "nodeNames":["127.0.0.1:37049_solr"]}} [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:303) [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> Caused by: java.lang.RuntimeException: failure [junit4] 2> at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction.process(TriggerIntegrationTest.java:989) [junit4] 2> at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:300) [junit4] 2> ... 6 more [junit4] 2> 2992322 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerL after 5000ms [junit4] 2> 2992322 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0 ms for event id=111c671a5cba7Tchxzysxhzwvurkxji6mquff34 [junit4] 2> 2994321 INFO (TEST-TriggerIntegrationTest.testListeners-seed#[F8655AEAAE497F5A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testListeners [junit4] 2> 2994352 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling [junit4] 2> 2994352 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 6 [junit4] 2> 2994352 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 2994352 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 2994353 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2994354 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 2994354 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 2994421 INFO (qtp8714987-22317) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994425 INFO (qtp21722514-22236) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994429 INFO (qtp501413-22227) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994493 INFO (qtp24184633-22295) [n:127.0.0.1:44791_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994493 DEBUG (qtp8714987-22321) [n:127.0.0.1:37049_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2994494 INFO (qtp8714987-22321) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=78 [junit4] 2> 2994494 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 2994495 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr] [junit4] 2> 2994495 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 2994495 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 2994499 INFO (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2994499 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2994499 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 2994500 INFO (qtp8714987-22322) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2994500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2994502 INFO (qtp21722514-22234) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994505 INFO (qtp501413-22235) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994508 INFO (qtp24184633-22297) [n:127.0.0.1:44791_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 2994509 DEBUG (qtp8714987-22323) [n:127.0.0.1:37049_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 2994509 INFO (qtp8714987-22323) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=13 [junit4] 2> 2994510 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 2994510 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr] [junit4] 2> 2994510 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 2994511 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr] [junit4] 2> 2994511 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 2994511 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 2994512 INFO (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 2994512 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 2994513 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 2994513 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 2994513 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4 [junit4] 2> 2994513 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:27:37+05:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2994514 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2994514 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2994514 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 2994514 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1c3242{/solr,null,AVAILABLE} [junit4] 2> 2994515 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@85eac0{SSL,[ssl, http/1.1]}{127.0.0.1:46149} [junit4] 2> 2994515 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.Server Started @2995791ms [junit4] 2> 2994515 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46149} [junit4] 2> 2994515 ERROR (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2994515 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.3.0 [junit4] 2> 2994516 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2994516 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2994516 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-02T02:17:43.745Z [junit4] 2> 2994517 INFO (zkConnectionManagerCallback-4602-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2994518 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2994526 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37235/solr [junit4] 2> 2994527 INFO (zkConnectionManagerCallback-4606-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2994529 INFO (zkConnectionManagerCallback-4608-thread-1-processing-n:127.0.0.1:46149_solr) [n:127.0.0.1:46149_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 2994533 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2994534 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2994535 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46149_solr [junit4] 2> 2994536 INFO (zkCallback-4579-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994536 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994536 INFO (zkCallback-4607-thread-1-processing-n:127.0.0.1:46149_solr) [n:127.0.0.1:46149_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994536 INFO (zkCallback-4597-thread-1-processing-n:127.0.0.1:37049_solr) [n:127.0.0.1:37049_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994536 INFO (zkCallback-4587-thread-1-processing-n:127.0.0.1:44791_solr) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994536 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5) [junit4] 2> 2994725 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46149.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2994735 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46149.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2994735 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46149.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@596850 [junit4] 2> 2994736 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [n:127.0.0.1:46149_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001/tempDir-001/node5/. [junit4] 2> 2995500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 2995500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 2995500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:46149_solr at time 301025167310314 [junit4] 2> 2995500 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger1 firing registered processor for nodes: [127.0.0.1:46149_solr] added at times [301025167310314], now=301025167351038 [junit4] 2> 2995501 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"111c7e22a7deaTchxzysxhzwvurkxji6mquff35", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":301025167310314, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301025167310314], [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 2995501 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_trigger2, node_added_trigger1] [junit4] 2> 2995501 INFO (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 2995502 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"111c7e22a7deaTchxzysxhzwvurkxji6mquff35", [junit4] 2> "source":"node_added_trigger1", [junit4] 2> "eventTime":301025167310314, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301025167310314], [junit4] 2> "_enqueue_time_":301025167628265, [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 2995502 INFO (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger1 [junit4] 2> 2995503 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 5000ms [junit4] 2> 2995503 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 5000ms [junit4] 2> 2995503 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=111c7e22a7deaTchxzysxhzwvurkxji6mquff35 [junit4] 2> 3000505 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger2 [junit4] 2> 3000505 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger1 [junit4] 2> 3000505 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 3000506 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 5 [junit4] 2> 3000506 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:46149_solr at time 301030172555675 [junit4] 2> 3000506 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger2 firing registered processor for nodes: [127.0.0.1:46149_solr] added at times [301030172555675], now=301030172638168 [junit4] 2> 3000506 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"111c90c80799bTchxzysxhzwvurkxji6mquff37", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":301030172555675, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301030172555675], [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 3000506 DEBUG (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_trigger2, node_added_trigger1] [junit4] 2> 3000507 INFO (ScheduledTrigger-8396-thread-2) [n:127.0.0.1:40773_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 3000507 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"111c90c80799bTchxzysxhzwvurkxji6mquff37", [junit4] 2> "source":"node_added_trigger2", [junit4] 2> "eventTime":301030172555675, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301030172555675], [junit4] 2> "_enqueue_time_":301030172962853, [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 3000507 INFO (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest last action at 1517537864731000000 current time = 1517537869736000000 [junit4] 2> real diff: 5005000000 [junit4] 2> min diff: 4998000000 [junit4] 2> 3000507 INFO (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_added_trigger2 [junit4] 2> 3000508 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 5000ms [junit4] 2> 3000508 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 5000ms [junit4] 2> 3000508 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1 ms for event id=111c90c80799bTchxzysxhzwvurkxji6mquff37 [junit4] 2> 3000512 INFO (qtp8714987-22317) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000515 INFO (qtp21722514-22236) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000518 INFO (qtp501413-22227) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000521 INFO (qtp24184633-22295) [n:127.0.0.1:44791_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000585 INFO (qtp13275895-22349) [n:127.0.0.1:46149_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000586 DEBUG (qtp8714987-22321) [n:127.0.0.1:37049_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 3000587 INFO (qtp8714987-22321) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=77 [junit4] 2> 3000587 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 3000587 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000588 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 3000588 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000588 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000588 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 3000588 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9 [junit4] 2> 3000590 INFO (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 3000590 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9 [junit4] 2> 3000591 DEBUG (ScheduledTrigger-8396-thread-3) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 5 [junit4] 2> 3000593 INFO (qtp8714987-22317) [n:127.0.0.1:37049_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000596 INFO (qtp21722514-22226) [n:127.0.0.1:39799_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000599 INFO (qtp501413-22229) [n:127.0.0.1:40773_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000603 INFO (qtp24184633-22296) [n:127.0.0.1:44791_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000609 INFO (qtp13275895-22346) [n:127.0.0.1:46149_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3000609 DEBUG (qtp13275895-22349) [n:127.0.0.1:46149_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 3000610 INFO (qtp13275895-22349) [n:127.0.0.1:46149_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=19 [junit4] 2> 3000610 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 3000610 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000610 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 3000611 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000611 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000611 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_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> 3000611 DEBUG (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:40773_solr, 127.0.0.1:37049_solr, 127.0.0.1:39799_solr, 127.0.0.1:44791_solr, 127.0.0.1:46149_solr] [junit4] 2> 3000611 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 3000613 INFO (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 3000613 DEBUG (OverseerAutoScalingTriggerThread-72077320986820613-127.0.0.1:40773_solr-n_0000000000) [n:127.0.0.1:40773_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 3000613 DEBUG (ScheduledTrigger-8396-thread-1) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger2 with currently live nodes: 5 [junit4] 2> 3000614 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@85eac0{SSL,[ssl, http/1.1]}{127.0.0.1:0} [junit4] 2> 3000614 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=17650260 [junit4] 2> 3000614 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 3000614 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1453133: rootName = solr_46149, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@188b69 [junit4] 2> 3000620 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 3000620 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@d62170: rootName = solr_46149, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@15efa63 [junit4] 2> 3000625 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 3000625 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@19488d5: rootName = solr_46149, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@a0a86c [junit4] 2> 3000627 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:46149_solr [junit4] 2> 3000627 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 3000627 INFO (zkCallback-4597-thread-1-processing-n:127.0.0.1:37049_solr) [n:127.0.0.1:37049_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000627 INFO (zkCallback-4579-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000627 INFO (zkCallback-4607-thread-1-processing-n:127.0.0.1:46149_solr) [n:127.0.0.1:46149_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000627 INFO (zkCallback-4587-thread-1-processing-n:127.0.0.1:44791_solr) [n:127.0.0.1:44791_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000627 INFO (zkCallback-4567-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000627 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 3000627 INFO (zkCallback-4569-thread-1-processing-n:127.0.0.1:39799_solr) [n:127.0.0.1:39799_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (5) -> (4) [junit4] 2> 3000629 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1c3242{/solr,null,UNAVAILABLE} [junit4] 2> 3000629 INFO (TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[F8655AEAAE497F5A]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 3001592 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger1 with currently live nodes: 4 [junit4] 2> 3001592 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:46149_solr [junit4] 2> 3001592 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:46149_solr] [junit4] 2> 3001593 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"111c94d47eec1Tchxzysxhzwvurkxji6mquff39", [junit4] 2> "source":"node_lost_trigger1", [junit4] 2> "eventTime":301031259369153, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301031259369153], [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 3001593 DEBUG (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_trigger2, node_added_trigger2, node_lost_trigger1, node_added_trigger1] [junit4] 2> 3001593 INFO (ScheduledTrigger-8396-thread-4) [n:127.0.0.1:40773_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 3001593 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"111c94d47eec1Tchxzysxhzwvurkxji6mquff39", [junit4] 2> "source":"node_lost_trigger1", [junit4] 2> "eventTime":301031259369153, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[301031259369153], [junit4] 2> "_enqueue_time_":301031259653842, [junit4] 2> "nodeNames":["127.0.0.1:46149_solr"]}} [junit4] 2> 3001594 INFO (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.TriggerIntegrationTest action executed from node_lost_trigger1 [junit4] 2> 3001594 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger2 after 5000ms [junit4] 2> 3001594 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger2 after 5000ms [junit4] 2> 3001594 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_trigger1 after 5000ms [junit4] 2> 3001594 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger1 after 5000ms [junit4] 2> 3001594 DEBUG (AutoscalingActionExecutor-8397-thread-1-processing-n:127.0.0.1:40773_solr) [n:127.0.0.1:40773_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0 ms for event id=111c94d [...truncated too long message...] ollection1.shard1.leader, tag=7299183 [junit4] 2> 3177654 INFO (coreCloseExecutor-8609-thread-2) [n:127.0.0.1:43967_solr c:collection1 s:shard1 r:core_node14 x:collection1_shard1_replica_n13] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard1.leader, tag=6418871 [junit4] 2> 3177656 INFO (jetty-closer-4552-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1902d57{/solr,null,UNAVAILABLE} [junit4] 2> 3177656 INFO (jetty-closer-4552-thread-2) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 3179078 WARN (zkCallback-4657-thread-1-processing-n:127.0.0.1:38791_solr) [n:127.0.0.1:38791_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 3179079 INFO (jetty-closer-4552-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@18c2c6{/solr,null,UNAVAILABLE} [junit4] 2> 3179079 INFO (jetty-closer-4552-thread-4) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 3179085 WARN (zkCallback-4697-thread-1-processing-n:127.0.0.1:44029_solr) [n:127.0.0.1:44029_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 3179085 INFO (jetty-closer-4552-thread-8) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1c129f5{/solr,null,UNAVAILABLE} [junit4] 2> 3179085 INFO (jetty-closer-4552-thread-8) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 3179086 ERROR (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-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> 3179086 INFO (SUITE-TriggerIntegrationTest-seed#[F8655AEAAE497F5A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37235 37235 [junit4] 2> 3184102 INFO (Thread-5589) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37235 37235 [junit4] 2> 3184102 WARN (Thread-5589) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 42 /solr/collections/collection1/terms/shard1 [junit4] 2> 22 /solr/aliases.json [junit4] 2> 21 /solr/security.json [junit4] 2> 9 /solr/configs/conf [junit4] 2> 2 /solr/collections/testMetricTrigger/terms/shard1 [junit4] 2> 2 /solr/collections/testMetricTrigger/terms/shard2 [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 139 /solr/collections/collection1/state.json [junit4] 2> 22 /solr/clusterprops.json [junit4] 2> 22 /solr/clusterstate.json [junit4] 2> 12 /solr/collections/testMetricTrigger/state.json [junit4] 2> 6 /solr/autoscaling.json [junit4] 2> 6 /solr/overseer_elect/election/72077320986820634-127.0.0.1:43967_solr-n_0000000007 [junit4] 2> 3 /solr/collections/collection1/leader_elect/shard1/election/72077320986820661-core_node3-n_0000000000 [junit4] 2> 2 /solr/overseer_elect/election/72077320986820622-127.0.0.1:37049_solr-n_0000000003 [junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/72077320986820667-core_node4-n_0000000001 [junit4] 2> 2 /solr/overseer_elect/election/72077320986820655-127.0.0.1:37317_solr-n_0000000014 [junit4] 2> 2 /solr/overseer_elect/election/72077320986820667-127.0.0.1:40173_solr-n_0000000018 [junit4] 2> 2 /solr/overseer_elect/election/72077320986820649-127.0.0.1:45251_solr-n_0000000012 [junit4] 2> 2 /solr/overseer_elect/election/72077320986820640-127.0.0.1:38791_solr-n_0000000009 [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 22 /solr/live_nodes [junit4] 2> 22 /solr/collections [junit4] 2> 6 /solr/overseer/queue-work [junit4] 2> 6 /solr/autoscaling/events/.auto_add_replicas [junit4] 2> 6 /solr/overseer/queue [junit4] 2> 6 /solr/overseer/collection-queue-work [junit4] 2> 2 /solr/autoscaling/events/node_lost_triggerMR [junit4] 2> 2 /solr/autoscaling/events/node_added_triggerCTOOR [junit4] 2> [junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_F8655AEAAE497F5A-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=Memory), x_s=TestBloomFilteredLucenePostings(BloomFilteringPostingsFormat(Lucene50(blocksize=128)))}, docValues:{_version_=DocValuesFormat(name=Memory)}, maxPointsInLeafNode=1419, maxMBSortInHeap=6.672222306441762, sim=RandomSimilarity(queryNorm=true): {}, locale=sr, timezone=America/Glace_Bay [junit4] 2> NOTE: Linux 4.13.0-32-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=1,free=292383816,total=491126784 [junit4] 2> NOTE: All tests run in this JVM: [TestOnReconnectListenerSupport, TestJsonRequest, QueryResultKeyTest, SoftAutoCommitTest, HttpSolrCallGetCoreTest, PeerSyncTest, TestSystemCollAutoCreate, TestSolrIndexConfig, DocExpirationUpdateProcessorFactoryTest, AddReplicaTest, SchemaApiFailureTest, FileUtilsTest, ClassificationUpdateProcessorIntegrationTest, DeleteNodeTest, TestHashQParserPlugin, TestChildDocTransformer, TestSmileRequest, XsltUpdateRequestHandlerTest, PreAnalyzedUpdateProcessorTest, TestSolrFieldCacheBean, CreateRoutedAliasTest, InfixSuggestersTest, DirectSolrConnectionTest, UninvertDocValuesMergePolicyTest, TestTrie, BitVectorTest, TestFuzzyAnalyzedSuggestions, TestNoOpRegenerator, TestSolrJ, TestPivotHelperCode, OverriddenZkACLAndCredentialsProvidersTest, TestFieldResource, AutoscalingHistoryHandlerTest, TestRTGBase, TestConfigsApi, TestDistribStateManager, CSVRequestHandlerTest, DistributedFacetPivotLargeTest, TestSurroundQueryParser, TestSegmentSorting, TestStressRecovery, TestCloudPivotFacet, TestExportWriter, TestReqParamsAPI, TestXIncludeConfig, TestQueryUtils, TestMaxScoreQueryParser, SystemInfoHandlerTest, TestSweetSpotSimilarityFactory, HdfsRestartWhileUpdatingTest, LargeFieldTest, TestLegacyField, QueryElevationComponentTest, TestLRUCache, TestJavabinTupleStreamParser, EnumFieldTest, TestCloudDeleteByQuery, PeerSyncReplicationTest, RestartWhileUpdatingTest, CurrencyFieldTypeTest, TestSubQueryTransformerDistrib, SaslZkACLProviderTest, SpatialHeatmapFacetsTest, AtomicUpdateProcessorFactoryTest, SolrJmxReporterTest, SliceStateTest, TestConfigSetsAPIExclusivity, TestTrieFacet, PrimUtilsTest, PathHierarchyTokenizerFactoryTest, DirectUpdateHandlerOptimizeTest, QueryEqualityTest, RequiredFieldsTest, TestLegacyTerms, TestCursorMarkWithoutUniqueKey, SpellCheckCollatorWithCollapseTest, ScriptEngineTest, TestPayloadScoreQParserPlugin, TestNRTOpen, TestMinMaxOnMultiValuedField, SortSpecParsingTest, LeaderFailoverAfterPartitionTest, TestPolicyCloud, ShardRoutingCustomTest, MetricUtilsTest, HighlighterTest, HttpPartitionTest, OverseerTest, TestReversedWildcardFilterFactory, SOLR749Test, LegacyCloudClusterPropTest, TestFoldingMultitermQuery, QueryParsingTest, TestSimpleTrackingShardHandler, TestReplicationHandler, TestRebalanceLeaders, DirectoryFactoryTest, SolrInfoBeanTest, TestSkipOverseerOperations, TestExclusionRuleCollectionAccess, ZkControllerTest, TestTolerantUpdateProcessorRandomCloud, DistributedFacetSimpleRefinementLongTailTest, TestUseDocValuesAsStored, JsonLoaderTest, TestLegacyFieldCache, SolrIndexMetricsTest, TestReplicaProperties, SuggesterFSTTest, TestSolr4Spatial, TestSolrCLIRunExample, TestBM25SimilarityFactory, SyncSliceTest, TestDistributedStatsComponentCardinality, TestSimpleTextCodec, TestPartialUpdateDeduplication, TestFieldSortValues, ZkStateWriterTest, DistributedQueryComponentOptimizationTest, AnalyticsQueryTest, CdcrUpdateLogTest, SolrShardReporterTest, UUIDUpdateProcessorFallbackTest, CollectionStateFormat2Test, TestReloadDeadlock, SearchRateTriggerTest, DistributedFacetPivotSmallTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, ZkSolrClientTest, TestDistributedSearch, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, TestRealTimeGet, TestReload, TestStressVersions, TestRangeQuery, HighlighterConfigTest, TestQuerySenderListener, AlternateDirectoryTest, CopyFieldTest, BadComponentTest, MultiTermTest, SampleTest, TestBinaryField, TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestSolrCoreProperties, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, SpellPossibilityIteratorTest, TestCodecSupport, TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, TestFastLRUCache, TestSuggestSpellingConverter, DOMUtilTest, ClusterStateTest, DistributedIntervalFacetingTest, TestTolerantSearch, TestEmbeddedSolrServerAdminHandler, TestJettySolrRunner, AsyncCallRequestStatusResponseTest, CloudExitableDirectoryReaderTest, ConfigSetsAPITest, ConnectionManagerTest, CreateCollectionCleanupTest, DistribCursorPagingTest, DocValuesNotIndexedTest, MoveReplicaHDFSFailoverTest, MultiThreadedOCPTest, OverseerTaskQueueTest, ReplaceNodeNoTargetTest, ReplicationFactorTest, SharedFSAutoReplicaFailoverTest, SolrCLIZkUtilsTest, SolrCloudExampleTest, TestAuthenticationFramework, TestCryptoKeys, TestDeleteCollectionOnDownNodes, TestDownShardTolerantSearch, TestLeaderElectionWithEmptyReplica, TestPrepRecovery, TestPullReplicaErrorHandling, TestSolrCloudWithDelegationTokens, TestSolrCloudWithSecureImpersonation, TestStressCloudBlindAtomicUpdates, ZkFailoverTest, TestLocalFSCloudBackupRestore, AutoAddReplicasIntegrationTest, TriggerIntegrationTest] [junit4] Completed [604/774 (1!)] on J1 in 204.48s, 14 tests, 1 failure, 1 error <<< FAILURES! [...truncated 44478 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org