Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4426/ Java: 64bit/jdk-9 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed. FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger Error Message: Stack Trace: java.lang.AssertionError at __randomizedtesting.SeedInfo.seed([8708A23038F85A7:B27CBDAC5C6753E8]:0) at org.junit.Assert.fail(Assert.java:92) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertNull(Assert.java:551) at org.junit.Assert.assertNull(Assert.java:562) at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1575) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:564) 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 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.base/java.lang.Thread.run(Thread.java:844) Build Log: [...truncated 12730 lines...] [junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest [junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/init-core-data-001 [junit4] 2> 967080 WARN (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7 [junit4] 2> 967080 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 967082 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth [junit4] 2> 967082 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 967083 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001 [junit4] 2> 967083 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 967083 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 967084 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 967087 ERROR (Thread-2242) [ ] 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> 967184 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:63950 [junit4] 2> 967193 INFO (zkConnectionManagerCallback-2578-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967197 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 967197 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 967200 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@69cc5ab0{/solr,null,AVAILABLE} [junit4] 2> 967200 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3abc49a0{/solr,null,AVAILABLE} [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1d30106d{HTTP/1.1,[http/1.1]}{127.0.0.1:63953} [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4a9d6480{HTTP/1.1,[http/1.1]}{127.0.0.1:63952} [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ] o.e.j.s.Server Started @969300ms [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ] o.e.j.s.Server Started @969300ms [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63953} [junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63952} [junit4] 2> 967201 ERROR (jetty-launcher-2575-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 967201 ERROR (jetty-launcher-2575-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-07T19:01:03.308181Z [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-07T19:01:03.308362Z [junit4] 2> 967203 INFO (zkConnectionManagerCallback-2580-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967204 INFO (zkConnectionManagerCallback-2582-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967204 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 967204 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 967251 INFO (jetty-launcher-2575-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr [junit4] 2> 967253 INFO (jetty-launcher-2575-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr [junit4] 2> 967254 INFO (zkConnectionManagerCallback-2586-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967257 INFO (zkConnectionManagerCallback-2590-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967260 INFO (zkConnectionManagerCallback-2592-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967262 INFO (zkConnectionManagerCallback-2594-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967396 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 967397 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:63953_solr [junit4] 2> 967398 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer (id=72158773892808709-127.0.0.1:63953_solr-n_0000000000) starting [junit4] 2> 967429 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 967432 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63953_solr [junit4] 2> 967433 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 967434 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 967434 INFO (zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 967436 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [] [junit4] 2> 967436 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1 [junit4] 2> 967436 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 967437 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63952_solr [junit4] 2> 967438 INFO (zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 967438 INFO (zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 967445 INFO (zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 967446 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 967447 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 967447 DEBUG (ScheduledTrigger-3928-thread-1) [n:127.0.0.1:63953_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 967490 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63953.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967493 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63952.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967501 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63953.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967501 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63953.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967504 INFO (jetty-launcher-2575-thread-2) [n:127.0.0.1:63953_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node2/. [junit4] 2> 967508 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63952.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967508 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63952.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967509 INFO (jetty-launcher-2575-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node1/. [junit4] 2> 967557 INFO (zkConnectionManagerCallback-2600-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967559 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1005c05c54f0007, likely client has closed socket [junit4] 2> 967561 INFO (zkConnectionManagerCallback-2604-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967563 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 967565 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:63950/solr ready [junit4] 2> 967579 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeMarkersRegistration [junit4] 2> 967580 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2 [junit4] 2> 967581 DEBUG (zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2 [junit4] 2> 967581 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2 [junit4] 2> 967583 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 967583 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 967584 DEBUG (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2 [junit4] 2> 967587 INFO (qtp1606393036-9999) [n:127.0.0.1:63953_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 967594 INFO (qtp1606393036-9999) [n:127.0.0.1:63953_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=7 [junit4] 2> 967595 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 967596 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 967596 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 967596 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Scavenging every 660000ms [junit4] 2> 967596 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6b8edc29{/solr,null,AVAILABLE} [junit4] 2> 967597 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@67209eec{HTTP/1.1,[http/1.1]}{127.0.0.1:63965} [junit4] 2> 967597 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server Started @969696ms [junit4] 2> 967597 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63965} [junit4] 2> 967597 ERROR (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 967598 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 967598 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 967598 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 967598 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-07T19:01:03.704190Z [junit4] 2> 967599 INFO (zkConnectionManagerCallback-2606-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967600 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 967613 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr [junit4] 2> 967614 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1005c05c54f0009, likely client has closed socket [junit4] 2> 967616 INFO (zkConnectionManagerCallback-2610-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967618 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 0x1005c05c54f000a, likely client has closed socket [junit4] 2> 967618 INFO (zkConnectionManagerCallback-2612-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 967626 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 967632 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 967635 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63965_solr [junit4] 2> 967639 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 967640 INFO (zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 967640 INFO (zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 967641 INFO (zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 967672 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63965.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967682 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63965.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967682 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63965.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 967684 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63965_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node3/. [junit4] 2> 967717 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest ====== KILL OVERSEER 1 [junit4] 2> 967718 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1d30106d{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 967718 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=871893683 [junit4] 2> 967718 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 967719 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4372d8de: rootName = solr_63953, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@27129e6c [junit4] 2> 967726 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 967726 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7790e795: rootName = solr_63953, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a [junit4] 2> 967732 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 967732 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1f38e677: rootName = solr_63953, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897 [junit4] 2> 967734 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:63953_solr [junit4] 2> 967735 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 967735 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 967736 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.Overseer Overseer (id=72158773892808709-127.0.0.1:63953_solr-n_0000000000) closing [junit4] 2> 967736 INFO (OverseerStateUpdate-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:63953_solr [junit4] 2> 967737 WARN (OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000) [n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 967737 DEBUG (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 967738 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 967738 INFO (zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 967738 INFO (zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 967739 INFO (zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr) [n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 967739 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3abc49a0{/solr,null,UNAVAILABLE} [junit4] 2> 967739 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 967740 INFO (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:63952_solr [junit4] 2> 967742 INFO (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer (id=72158773892808710-127.0.0.1:63952_solr-n_0000000001) starting [junit4] 2> 967751 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger [junit4] 2> 967752 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3 [junit4] 2> 967753 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 967753 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion -1 [junit4] 2> 967753 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3 [junit4] 2> 967755 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 967756 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3 [junit4] 2> 967756 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 968759 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 969780 DEBUG (ScheduledTrigger-3943-thread-2) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 970784 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 971785 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 972747 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD TRIGGERS [junit4] 2> 972753 INFO (qtp264083190-10007) [n:127.0.0.1:63952_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> 972755 INFO (qtp1295431108-10061) [n:127.0.0.1:63965_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> 972756 DEBUG (qtp264083190-10003) [n:127.0.0.1:63952_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 972756 INFO (qtp264083190-10003) [n:127.0.0.1:63952_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=5 [junit4] 2> 972757 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4 [junit4] 2> 972758 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 972758 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventMarkerAction}], enabled=true} [junit4] 2> 972758 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 972758 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4 [junit4] 2> 972759 INFO (qtp264083190-10007) [n:127.0.0.1:63952_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> 972759 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_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> 972760 DEBUG (qtp264083190-10005) [n:127.0.0.1:63952_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 972760 INFO (qtp264083190-10005) [n:127.0.0.1:63952_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=3 [junit4] 2> 972761 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 972761 INFO (qtp264083190-10008) [n:127.0.0.1:63952_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 972761 INFO (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventMarkerAction init [junit4] 2> 972762 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 972762 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 972763 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventMarkerAction}], enabled=true} [junit4] 2> 972763 DEBUG (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63952_solr, 127.0.0.1:63965_solr] [junit4] 2> 972764 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 4 [junit4] 2> 972764 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 972764 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR [junit4] 2> 972764 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 972767 INFO (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventMarkerAction init [junit4] 2> 972768 DEBUG (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 972768 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 [junit4] 2> 972769 INFO (qtp264083190-10008) [n:127.0.0.1:63952_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=8 [junit4] 2> 972769 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD NODE 1 [junit4] 2> 972770 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 972771 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 972771 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 972771 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 972772 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5705b223{/solr,null,AVAILABLE} [junit4] 2> 972772 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4df027ed{HTTP/1.1,[http/1.1]}{127.0.0.1:63981} [junit4] 2> 972772 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server Started @974871ms [junit4] 2> 972772 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63981} [junit4] 2> 972772 ERROR (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 972772 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 972773 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 972773 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 972773 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-07T19:01:08.879086Z [junit4] 2> 972774 INFO (zkConnectionManagerCallback-2616-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 972775 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 972781 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr [junit4] 2> 972783 INFO (zkConnectionManagerCallback-2620-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 972785 INFO (zkConnectionManagerCallback-2622-thread-1-processing-n:127.0.0.1:63981_solr) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 972786 DEBUG (ScheduledTrigger-3943-thread-2) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 972796 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 972800 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 972804 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63981_solr [junit4] 2> 972806 INFO (zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 972806 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 972806 INFO (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 972807 INFO (zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 972853 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63981.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 972862 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63981.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 972862 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63981.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 972863 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [n:127.0.0.1:63981_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node4/. [junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR [junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 3 [junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:63981_solr at time 1543888754788649 [junit4] 2> 973791 DEBUG (ScheduledTrigger-3943-thread-1) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 3 [junit4] 2> 974773 INFO (OverseerCollectionConfigSetProcessor-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR [junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR firing registered processor for nodes: [127.0.0.1:63981_solr] added at times [1543888754788649], now=1543889757095677 [junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"57c289ccd4929T590altvb92ev1m9vvmhhnhcob", [junit4] 2> "source":"node_added_triggerMR", [junit4] 2> "eventTime":1543888754788649, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543888754788649], [junit4] 2> "nodeNames":["127.0.0.1:63981_solr"]}} [junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-2) [n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 3 [junit4] 2> 974780 DEBUG (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas] [junit4] 2> 974781 INFO (ScheduledTrigger-3943-thread-4) [n:127.0.0.1:63952_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 974781 DEBUG (AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"57c289ccd4929T590altvb92ev1m9vvmhhnhcob", [junit4] 2> "source":"node_added_triggerMR", [junit4] 2> "eventTime":1543888754788649, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543888754788649], [junit4] 2> "_enqueue_time_":1543889757742589, [junit4] 2> "nodeNames":["127.0.0.1:63981_solr"]}} [junit4] 2> 974783 DEBUG (AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_triggerMR after 5000ms [junit4] 2> 974783 DEBUG (AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerMR after 5000ms [junit4] 2> 974783 DEBUG (AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 5000ms [junit4] 2> 974783 DEBUG (AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2 ms for event id=57c289ccd4929T590altvb92ev1m9vvmhhnhcob [junit4] 2> 977896 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest ====== KILL OVERSEER 2 [junit4] 2> 977898 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4a9d6480{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 977898 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1963702184 [junit4] 2> 977899 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 977899 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4c184e: rootName = solr_63952, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@5fe0e8b [junit4] 2> 977912 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 977913 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1d9db155: rootName = solr_63952, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a [junit4] 2> 977920 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 977921 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5fd22880: rootName = solr_63952, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897 [junit4] 2> 977923 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:63952_solr [junit4] 2> 977926 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 977927 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 977927 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.Overseer Overseer (id=72158773892808710-127.0.0.1:63952_solr-n_0000000001) closing [junit4] 2> 977928 INFO (OverseerStateUpdate-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:63952_solr [junit4] 2> 977929 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 977929 INFO (zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 977929 INFO (zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr) [n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 977929 INFO (zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 977930 DEBUG (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly [junit4] 2> 977931 WARN (OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001) [n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting. [junit4] 2> 977935 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@69cc5ab0{/solr,null,UNAVAILABLE} [junit4] 2> 977935 INFO (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:63965_solr [junit4] 2> 977935 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 977940 INFO (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.Overseer Overseer (id=72158773892808715-127.0.0.1:63965_solr-n_0000000002) starting [junit4] 2> 977977 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5 [junit4] 2> 977978 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 977979 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 977979 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventMarkerAction}], enabled=true} [junit4] 2> 977980 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 977980 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion -1 [junit4] 2> 977980 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5 [junit4] 2> 977981 INFO (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventMarkerAction init [junit4] 2> 977981 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:63952_solr [junit4] 2> 977984 INFO (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest TestEventMarkerAction init [junit4] 2> 977985 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 [junit4] 2> 977985 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:63952_solr [junit4] 2> 977986 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5 [junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-2) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR [junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-2) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-3) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-3) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:63952_solr [junit4] 2> 978997 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_triggerMR with currently live nodes: 2 [junit4] 2> 978997 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:63952_solr] [junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerMR [junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"57c29979df94dT590altvb92ev1m9vvmhhnhcod", [junit4] 2> "source":"node_lost_triggerMR", [junit4] 2> "eventTime":1543892962769229, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543892962769229], [junit4] 2> "nodeNames":["127.0.0.1:63952_solr"]}} [junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-2) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 [junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas] [junit4] 2> 978999 INFO (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 979000 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"57c29979df94dT590altvb92ev1m9vvmhhnhcod", [junit4] 2> "source":"node_lost_triggerMR", [junit4] 2> "eventTime":1543892962769229, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543892962769229], [junit4] 2> "_enqueue_time_":1543893976120858, [junit4] 2> "nodeNames":["127.0.0.1:63952_solr"]}} [junit4] 2> 979000 INFO (TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeMarkersRegistration [junit4] 2> 979005 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_lost_triggerMR after 5000ms [junit4] 2> 979005 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerMR after 5000ms [junit4] 2> 979005 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 5000ms [junit4] 2> 979005 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 5 ms for event id=57c29979df94dT590altvb92ev1m9vvmhhnhcod [junit4] 2> 979015 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger [junit4] 2> 979015 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 6 [junit4] 2> 979016 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6 [junit4] 2> 979016 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6 [junit4] 2> 979021 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 979021 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 979022 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6 [junit4] 2> 979026 INFO (qtp1230244092-10098) [n:127.0.0.1:63981_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=1 [junit4] 2> 979028 INFO (qtp1295431108-10066) [n:127.0.0.1:63965_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> 979028 DEBUG (qtp1295431108-10063) [n:127.0.0.1:63965_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 979029 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=6 [junit4] 2> 979029 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7 [junit4] 2> 979030 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 979030 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true} [junit4] 2> 979031 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7 [junit4] 2> 979033 INFO (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 979034 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 979034 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 979034 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 7, lastZnodeVersion 7 [junit4] 2> 979035 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 979035 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2 [junit4] 2> 979035 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 979035 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 979035 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 979036 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4f54fc87{/solr,null,AVAILABLE} [junit4] 2> 979036 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@585a3f39{HTTP/1.1,[http/1.1]}{127.0.0.1:63995} [junit4] 2> 979036 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.Server Started @981135ms [junit4] 2> 979036 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=63995} [junit4] 2> 979036 ERROR (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 979037 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0 [junit4] 2> 979037 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 979037 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 979037 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-07T19:01:15.143548Z [junit4] 2> 979039 INFO (zkConnectionManagerCallback-2626-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 979039 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 979045 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr [junit4] 2> 979047 INFO (zkConnectionManagerCallback-2630-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 979050 INFO (zkConnectionManagerCallback-2632-thread-1-processing-n:127.0.0.1:63995_solr) [n:127.0.0.1:63995_solr ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 979059 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 979063 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 979066 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63995_solr [junit4] 2> 979068 INFO (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 979069 INFO (zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 979069 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 979069 INFO (zkCallback-2631-thread-1-processing-n:127.0.0.1:63995_solr) [n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 979110 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63995.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 979119 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63995.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 979119 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_63995.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c [junit4] 2> 979121 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [n:127.0.0.1:63995_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node5/. [junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:63995_solr at time 1543895020252947 [junit4] 2> 981053 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 981054 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_trigger [junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3 [junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger firing registered processor for nodes: [127.0.0.1:63995_solr] added at times [1543895020252947], now=1543897034718748 [junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"57c2a1240af13T590altvb92ev1m9vvmhhnhcof", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1543895020252947, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543895020252947], [junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}} [junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_added_trigger] [junit4] 2> 982058 INFO (ScheduledTrigger-3954-thread-4) [n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 982058 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for { [junit4] 2> "id":"57c2a1240af13T590altvb92ev1m9vvmhhnhcof", [junit4] 2> "source":"node_added_trigger", [junit4] 2> "eventTime":1543895020252947, [junit4] 2> "eventType":"NODEADDED", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543895020252947], [junit4] 2> "_enqueue_time_":1543897035012807, [junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}} [junit4] 2> 982063 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 5000ms [junit4] 2> 982063 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 4 ms for event id=57c2a1240af13T590altvb92ev1m9vvmhhnhcof [junit4] 2> 982064 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_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> 982066 INFO (qtp1230244092-10102) [n:127.0.0.1:63981_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> 982067 INFO (qtp296880580-10138) [n:127.0.0.1:63995_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> 982067 DEBUG (qtp296880580-10134) [n:127.0.0.1:63995_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 982068 INFO (qtp296880580-10134) [n:127.0.0.1:63995_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=7 [junit4] 2> 982068 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 8 [junit4] 2> 982069 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:63995_solr, 127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 982069 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true} [junit4] 2> 982069 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 8 [junit4] 2> 982070 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 982070 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 8, lastZnodeVersion 8 [junit4] 2> 984069 INFO (TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger [junit4] 2> 984090 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger [junit4] 2> 984091 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 9 [junit4] 2> 984092 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 9 [junit4] 2> 984092 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 9 [junit4] 2> 984094 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers [junit4] 2> 984094 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 984095 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 9, lastZnodeVersion 9 [junit4] 2> 984097 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 984105 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=8 [junit4] 2> 984108 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_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> 984109 INFO (qtp1230244092-10103) [n:127.0.0.1:63981_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> 984110 INFO (qtp296880580-10140) [n:127.0.0.1:63995_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> 984111 DEBUG (qtp1230244092-10102) [n:127.0.0.1:63981_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration [junit4] 2> 984115 INFO (qtp1230244092-10102) [n:127.0.0.1:63981_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling params={wt=javabin&version=2} status=0 QTime=8 [junit4] 2> 984116 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 10 [junit4] 2> 984116 DEBUG (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:63995_solr, 127.0.0.1:63981_solr, 127.0.0.1:63965_solr] [junit4] 2> 984116 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 10 [junit4] 2> 984118 INFO (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init [junit4] 2> 984118 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers [junit4] 2> 984121 DEBUG (OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 10, lastZnodeVersion 10 [junit4] 2> 984122 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@585a3f39{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 984122 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1051152417 [junit4] 2> 984122 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 3 [junit4] 2> 984122 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 984122 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1b6347f6: rootName = solr_63995, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3cfb960e [junit4] 2> 984133 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 984133 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1c48ba13: rootName = solr_63995, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a [junit4] 2> 984140 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 984140 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2485358e: rootName = solr_63995, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897 [junit4] 2> 984143 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:63995_solr [junit4] 2> 984144 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null [junit4] 2> 984144 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 984145 INFO (zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr) [n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 984145 INFO (zkCallback-2603-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 984145 INFO (zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 984145 INFO (zkCallback-2631-thread-1-processing-n:127.0.0.1:63995_solr) [n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2) [junit4] 2> 984147 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4f54fc87{/solr,null,UNAVAILABLE} [junit4] 2> 984147 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 985149 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 985149 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:63995_solr [junit4] 2> 986108 INFO (OverseerCollectionConfigSetProcessor-72158773892808715-127.0.0.1:63965_solr-n_0000000002) [n:127.0.0.1:63965_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 2 [junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:63995_solr] [junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: { [junit4] 2> "id":"57c2b429c8df4T590altvb92ev1m9vvmhhnhcoh", [junit4] 2> "source":"node_lost_trigger", [junit4] 2> "eventTime":1543900126547444, [junit4] 2> "eventType":"NODELOST", [junit4] 2> "properties":{ [junit4] 2> "eventTimes":[1543900126547444], [junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}} [junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [node_lost_trigger] [junit4] 2> 986151 INFO (ScheduledTrigger-3954-thread-1) [n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging. [junit4] 2> 986151 DEBUG (AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr) [n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing [...truncated too long message...] PoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 1159727 WARN (zkCallback-2796-thread-1-processing-n:127.0.0.1:64537_solr) [n:127.0.0.1:64537_solr ] o.a.s.c.ZkController Unable to register nodeLost path for 127.0.0.1:64537_solr [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:64537_solr [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:130) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) [junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:786) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:365) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:365) [junit4] 2> at org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:882) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:704) [junit4] 2> at java.base/java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4724) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090) [junit4] 2> at org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269) [junit4] 2> at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514) [junit4] 2> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) [junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167) [junit4] 2> at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641) [junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844) [junit4] 2> 1159726 WARN (zkCallback-2766-thread-2-processing-n:127.0.0.1:64426_solr) [n:127.0.0.1:64426_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 1159726 INFO (jetty-closer-2576-thread-12) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1159728 INFO (jetty-closer-2576-thread-11) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7d90353b{/solr,null,UNAVAILABLE} [junit4] 2> 1159728 INFO (jetty-closer-2576-thread-11) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1159742 WARN (zkCallback-2796-thread-3-processing-n:127.0.0.1:64537_solr) [n:127.0.0.1:64537_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes] [junit4] 2> 1159743 INFO (jetty-closer-2576-thread-13) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7e49731d{/solr,null,UNAVAILABLE} [junit4] 2> 1159743 INFO (jetty-closer-2576-thread-13) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1160007 INFO (jetty-closer-2576-thread-6) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5803a918{/solr,null,UNAVAILABLE} [junit4] 2> 1160007 INFO (jetty-closer-2576-thread-6) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 1160009 ERROR (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-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> 1160009 INFO (SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:63950 63950 [junit4] 2> 1160024 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:63950 63950 [junit4] 2> 1160169 WARN (Thread-2242) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 22 /solr/clusterprops.json [junit4] 2> 22 /solr/aliases.json [junit4] 2> 21 /solr/security.json [junit4] 2> 21 /solr/collections/collection1/terms/shard1 [junit4] 2> 6 /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> 64 /solr/collections/collection1/state.json [junit4] 2> 22 /solr/clusterstate.json [junit4] 2> 11 /solr/collections/testMetricTrigger/state.json [junit4] 2> 6 /solr/autoscaling.json [junit4] 2> 3 /solr/overseer_elect/election/72158773892808742-127.0.0.1:64180_solr-n_0000000011 [junit4] 2> 3 /solr/overseer_elect/election/72158773892808752-127.0.0.1:64302_solr-n_0000000014 [junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/72158773892808736-core_node4-n_0000000000 [junit4] 2> 2 /solr/overseer_elect/election/72158773892808730-127.0.0.1:64129_solr-n_0000000007 [junit4] 2> 2 /solr/overseer_elect/election/72158773892808736-127.0.0.1:64172_solr-n_0000000009 [junit4] 2> 2 /solr/overseer_elect/election/72158773892808761-127.0.0.1:64426_solr-n_0000000017 [junit4] 2> 2 /solr/overseer_elect/election/72158773892808718-127.0.0.1:63981_solr-n_0000000003 [junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/72158773892808739-core_node3-n_0000000001 [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: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@699ee3c2), locale=en-AT, timezone=SystemV/EST5 [junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 (64-bit)/cpus=3,threads=1,free=153156352,total=360710144 [junit4] 2> NOTE: All tests run in this JVM: [TestRestoreCore, TestBulkSchemaAPI, NodeLostTriggerTest, ClusterStateUpdateTest, AsyncCallRequestStatusResponseTest, EchoParamsTest, TestDocumentBuilder, SolrXmlInZkTest, SystemLogListenerTest, TlogReplayBufferedWhileIndexingTest, DeleteReplicaTest, CleanupOldIndexTest, TestSolrDeletionPolicy2, BasicAuthIntegrationTest, TestDistributedGrouping, HdfsRecoveryZkTest, ReplicationFactorTest, TestCollapseQParserPlugin, TestSolrQueryParser, ParsingFieldUpdateProcessorsTest, TestStressInPlaceUpdates, TestManagedStopFilterFactory, TestCollectionsAPIViaSolrCloudCluster, DirectUpdateHandlerTest, SolrShardReporterTest, ScriptEngineTest, BufferStoreTest, FileBasedSpellCheckerTest, PropertiesRequestHandlerTest, HdfsAutoAddReplicasIntegrationTest, OverseerRolesTest, TestIndexingPerformance, SparseHLLTest, TestCoreBackup, RegexBoostProcessorTest, SpatialRPTFieldTypeTest, ComputePlanActionTest, TestGraphTermsQParserPlugin, BasicDistributedZk2Test, TestDynamicLoading, CdcrVersionReplicationTest, TestSolr4Spatial2, ZkSolrClientTest, TestFreeTextSuggestions, DistributedIntervalFacetingTest, TestSimDistributedQueue, TestSolrCoreProperties, UUIDFieldTest, ZkShardTermsTest, TestSolrCloudWithDelegationTokens, DistanceUnitsTest, TestClassicSimilarityFactory, TestSolr4Spatial, SoftAutoCommitTest, TestConfigSetProperties, TestRandomRequestDistribution, BadIndexSchemaTest, BasicFunctionalityTest, TestDocBasedVersionConstraints, TestSchemaNameResource, SolrSlf4jReporterTest, TestExactStatsCache, TolerantUpdateProcessorTest, ReplaceNodeNoTargetTest, TestScoreJoinQPScore, IndexSchemaTest, TestFastLRUCache, HdfsCollectionsAPIDistributedZkTest, TestSubQueryTransformerDistrib, BooleanFieldTest, NotRequiredUniqueKeyTest, CloudMLTQParserTest, TestDynamicFieldCollectionResource, DistributedQueryComponentOptimizationTest, BaseCdcrDistributedZkTest, TestOrdValues, JSONWriterTest, TestSchemaManager, SolrGangliaReporterTest, TestExtendedDismaxParser, TestRawTransformer, DebugComponentTest, TestStressReorder, MetricTriggerTest, ClassificationUpdateProcessorFactoryTest, TestWriterPerf, TestInfoStreamLogging, URLClassifyProcessorTest, RecoveryAfterSoftCommitTest, TestRequestForwarding, HdfsNNFailoverTest, HealthCheckHandlerTest, TestExportWriter, TestManagedSynonymGraphFilterFactory, TestSolrConfigHandlerConcurrent, SuggesterTest, TestSimpleTrackingShardHandler, TestSolrCloudWithSecureImpersonation, SegmentsInfoRequestHandlerTest, TestDistributedMissingSort, TestNumericTerms64, SyncSliceTest, TestNumericTokenStream, TestConfigSetsAPIZkFailure, CreateRoutedAliasTest, TriggerIntegrationTest] [junit4] Completed [227/775 (1!)] on J1 in 193.10s, 14 tests, 1 failure <<< FAILURES! [...truncated 42714 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org