Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/446/
Java: 64bit/jdk-9 -XX:-UseCompressedOops -XX:+UseParallelGC
2 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger
Error Message:
Stack Trace:
java.lang.NullPointerException
at
__randomizedtesting.SeedInfo.seed([41E1348A3C1B7E92:FBED030563F3A8DD]:0)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1565)
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)
FAILED: org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory
Error Message:
expected:<5> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<5> but was:<0>
at
__randomizedtesting.SeedInfo.seed([41E1348A3C1B7E92:2C1D907786538195]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at
org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory(AutoscalingHistoryHandlerTest.java:265)
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 13008 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/init-core-data-001
[junit4] 2> 1389454 WARN
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 1389454 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1389455 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-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> 1389455 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 1389455 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/tempDir-001
[junit4] 2> 1389455 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1389456 INFO (Thread-2546) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1389456 INFO (Thread-2546) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1389460 ERROR (Thread-2546) [ ] 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> 1389562 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:50664
[junit4] 2> 1389573 INFO (zkConnectionManagerCallback-5955-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389577 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1389577 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1389579 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1389579 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1389579 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1389580 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@77c9b3c7{/solr,null,AVAILABLE}
[junit4] 2> 1389580 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1389580 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1389580 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1389580 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@1e08560e{/solr,null,AVAILABLE}
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1ae0268{HTTP/1.1,[http/1.1]}{127.0.0.1:50666}
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@7f89cc2c{HTTP/1.1,[http/1.1]}{127.0.0.1:50667}
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.e.j.s.Server Started @1391574ms
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.e.j.s.Server Started @1391574ms
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=50667}
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=50666}
[junit4] 2> 1389583 ERROR (jetty-launcher-5952-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1389583 ERROR (jetty-launcher-5952-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T14:08:23.238730Z
[junit4] 2> 1389583 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T14:08:23.238756Z
[junit4] 2> 1389585 INFO (zkConnectionManagerCallback-5957-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389585 INFO (zkConnectionManagerCallback-5959-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389588 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1389588 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1389603 INFO (jetty-launcher-5952-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50664/solr
[junit4] 2> 1389603 INFO (jetty-launcher-5952-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50664/solr
[junit4] 2> 1389605 INFO (zkConnectionManagerCallback-5965-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389605 INFO (zkConnectionManagerCallback-5967-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389609 INFO
(zkConnectionManagerCallback-5969-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389609 INFO
(zkConnectionManagerCallback-5971-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389774 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1389776 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1389777 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:50667_solr
[junit4] 2> 1389778 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:50666_solr
[junit4] 2> 1389778 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.Overseer Overseer
(id=72074879465684997-127.0.0.1:50667_solr-n_0000000000) starting
[junit4] 2> 1389780 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1389781 INFO
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1389791 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1389793 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 1389794 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:50666_solr]
[junit4] 2> 1389794 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1389794 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 1389795 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:50667_solr
[junit4] 2> 1389797 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1389797 INFO
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1389798 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1389799 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1389800 DEBUG (ScheduledTrigger-5735-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1389838 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50666.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389858 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50666.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389859 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50666.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389861 INFO (jetty-launcher-5952-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/tempDir-001/node2/.
[junit4] 2> 1389863 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50667.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389884 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50667.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389885 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50667.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1389889 INFO (jetty-launcher-5952-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/tempDir-001/node1/.
[junit4] 2> 1389924 INFO (zkConnectionManagerCallback-5977-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389929 INFO (zkConnectionManagerCallback-5981-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1389930 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1389932 INFO
(SUITE-TriggerIntegrationTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:50664/solr ready
[junit4] 2> 1389952 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testContinueTriggersOnOverseerRestart
[junit4] 2> 1389952 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 2
[junit4] 2> 1389953 DEBUG
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 1389953 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 1389956 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1389956 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1389957 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1389966 INFO (qtp571970206-17239) [n:127.0.0.1:50666_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1389973 INFO (qtp571970206-17239) [n:127.0.0.1:50666_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> 1389981 INFO (qtp571970206-17248) [n:127.0.0.1:50666_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> 1389983 INFO (qtp1618298141-17245) [n:127.0.0.1:50667_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> 1389983 DEBUG (qtp1618298141-17238) [n:127.0.0.1:50667_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1389984 INFO (qtp1618298141-17238) [n:127.0.0.1:50667_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1389984 DEBUG
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 1389985 DEBUG
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50666_solr, 127.0.0.1:50667_solr]
[junit4] 2> 1389985 DEBUG
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerCTOOR instantiated with properties: {event=nodeAdded,
waitFor=2, actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1389985 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 1389988 INFO
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1389989 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@7f89cc2c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1389990 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1389990 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=720262372
[junit4] 2> 1389990 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 1389990 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7669e73b: rootName =
solr_50667, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@15fb6fa9
[junit4] 2> 1389993 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1389993 DEBUG (ScheduledTrigger-5735-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1389994 DEBUG (ScheduledTrigger-5735-thread-1)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1390001 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 1390001 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@5c61b565: rootName =
solr_50667, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@4c723e36
[junit4] 2> 1390008 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 1390008 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@20a6e3b9: rootName =
solr_50667, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@61967348
[junit4] 2> 1390010 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:50667_solr
[junit4] 2> 1390012 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 1390013 INFO (zkCallback-5980-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1390013 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 1390014 INFO
(zkCallback-5968-thread-1-processing-n:127.0.0.1:50667_solr)
[n:127.0.0.1:50667_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (1)
[junit4] 2> 1390014 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1390014 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.Overseer Overseer
(id=72074879465684997-127.0.0.1:50667_solr-n_0000000000) closing
[junit4] 2> 1390014 INFO
(OverseerStateUpdate-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:50667_solr
[junit4] 2> 1390015 WARN
(OverseerAutoScalingTriggerThread-72074879465684997-127.0.0.1:50667_solr-n_0000000000)
[n:127.0.0.1:50667_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1390026 DEBUG
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed
explicitly
[junit4] 2> 1390027 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:50666_solr
[junit4] 2> 1390027 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1e08560e{/solr,null,UNAVAILABLE}
[junit4] 2> 1390028 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1390030 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.Overseer Overseer
(id=72074879465684998-127.0.0.1:50666_solr-n_0000000001) starting
[junit4] 2> 1390048 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1390049 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 1390050 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50666_solr]
[junit4] 2> 1390050 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerCTOOR instantiated with properties: {event=nodeAdded,
waitFor=2, actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1390051 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:50666_solr]
[junit4] 2> 1390051 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion -1
[junit4] 2> 1390051 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 1390051 INFO
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1390053 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1390053 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1390055 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1390056 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1391063 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1391064 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1391064 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1392068 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1392068 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1392068 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1393076 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1393076 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1393076 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1394077 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1394077 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1394077 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1395079 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1395079 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1395079 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1396081 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1396081 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1396082 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1397082 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1397082 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1397082 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1398083 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1398083 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1398083 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1399093 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1399093 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1399093 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1400041 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1400043 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1400043 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1400043 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1400044 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@70513e6{/solr,null,AVAILABLE}
[junit4] 2> 1400044 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@2b89e12e{HTTP/1.1,[http/1.1]}{127.0.0.1:50707}
[junit4] 2> 1400044 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.e.j.s.Server Started @1402035ms
[junit4] 2> 1400044 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=50707}
[junit4] 2> 1400044 ERROR
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 1400045 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™
version 7.3.0
[junit4] 2> 1400045 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 1400045 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1400045 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T14:08:33.700944Z
[junit4] 2> 1400048 INFO (zkConnectionManagerCallback-5983-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1400049 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1400058 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50664/solr
[junit4] 2> 1400060 INFO (zkConnectionManagerCallback-5987-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1400064 INFO
(zkConnectionManagerCallback-5989-thread-1-processing-n:127.0.0.1:50707_solr)
[n:127.0.0.1:50707_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1400084 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1400089 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1400094 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1400094 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1400094 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1400096 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:50707_solr
[junit4] 2> 1400098 INFO (zkCallback-5980-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1400098 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1400099 INFO
(zkCallback-5988-thread-1-processing-n:127.0.0.1:50707_solr)
[n:127.0.0.1:50707_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1400180 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50707.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1400202 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50707.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1400202 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50707.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1400203 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50707_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/tempDir-001/node3/.
[junit4] 2> 1401099 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1401099 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1401099 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1401099 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:50707_solr at time 263766336661224
[junit4] 2> 1402110 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1402110 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1402110 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1403111 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 1403111 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1403111 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1403111 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerCTOOR firing registered processor for nodes:
[127.0.0.1:50707_solr] added at times [263766336661224], now=263768348963483
[junit4] 2> 1403111 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"efe4e2cce6e8T37a4fcbxg5ho5tnjdbev0dww",
[junit4] 2> "source":"node_added_triggerCTOOR",
[junit4] 2> "eventTime":263766336661224,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263766336661224],
[junit4] 2> "nodeNames":["127.0.0.1:50707_solr"]}}
[junit4] 2> 1403112 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[.auto_add_replicas, node_added_triggerCTOOR]
[junit4] 2> 1403113 INFO (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1403113 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"efe4e2cce6e8T37a4fcbxg5ho5tnjdbev0dww",
[junit4] 2> "source":"node_added_triggerCTOOR",
[junit4] 2> "eventTime":263766336661224,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263766336661224],
[junit4] 2> "_enqueue_time_":263768349577191,
[junit4] 2> "nodeNames":["127.0.0.1:50707_solr"]}}
[junit4] 2> 1403114 INFO
(TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[41E1348A3C1B7E92])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testContinueTriggersOnOverseerRestart
[junit4] 2> 1403119 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
.auto_add_replicas after 5000ms
[junit4] 2> 1403119 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_triggerCTOOR after 5000ms
[junit4] 2> 1403119 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 6
ms for event id=efe4e2cce6e8T37a4fcbxg5ho5tnjdbev0dww
[junit4] 2> 1403135 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 1403136 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
[junit4] 2> 1403137 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 1403137 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 1403144 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1403144 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1403145 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1403151 INFO (qtp571970206-17250) [n:127.0.0.1:50666_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> 1403154 INFO (qtp1584501771-17313) [n:127.0.0.1:50707_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> 1403154 DEBUG (qtp571970206-17241) [n:127.0.0.1:50666_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1403155 INFO (qtp571970206-17241) [n:127.0.0.1:50666_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1403155 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 1403156 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1403156 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1403156 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 1403159 INFO (qtp571970206-17241) [n:127.0.0.1:50666_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> 1403161 INFO (qtp1584501771-17318) [n:127.0.0.1:50707_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> 1403161 DEBUG (qtp1584501771-17317) [n:127.0.0.1:50707_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1403162 INFO
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1403163 INFO (qtp1584501771-17317) [n:127.0.0.1:50707_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1403164 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1403164 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 1403165 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1403165 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1403165 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1403165 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1403165 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1403165 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1403166 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 6
[junit4] 2> 1403166 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 1403169 INFO
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1403170 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1403171 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1403171 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 1403171 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1403174 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T18:27:37-03:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1403183 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1403183 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1403183 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@f0f5699{/solr,null,AVAILABLE}
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@4e19aef5{HTTP/1.1,[http/1.1]}{127.0.0.1:50723}
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.Server Started @1405175ms
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=50723}
[junit4] 2> 1403184 ERROR
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 1403184 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1403185 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-11T14:08:36.840006Z
[junit4] 2> 1403186 INFO (zkConnectionManagerCallback-5993-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1403186 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1403196 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50664/solr
[junit4] 2> 1403201 INFO (zkConnectionManagerCallback-5997-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1403209 INFO
(zkConnectionManagerCallback-5999-thread-1-processing-n:127.0.0.1:50723_solr)
[n:127.0.0.1:50723_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1403225 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 1403229 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1403234 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:50723_solr
[junit4] 2> 1403241 INFO (zkCallback-5980-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1403241 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1403242 INFO
(zkCallback-5998-thread-1-processing-n:127.0.0.1:50723_solr)
[n:127.0.0.1:50723_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1403242 INFO
(zkCallback-5988-thread-1-processing-n:127.0.0.1:50707_solr)
[n:127.0.0.1:50707_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1403305 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50723.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1403325 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50723.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1403326 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_50723.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5661b419
[junit4] 2> 1403331 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92])
[n:127.0.0.1:50723_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_41E1348A3C1B7E92-001/tempDir-001/node4/.
[junit4] 2> 1404169 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1404169 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1404169 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:50723_solr at time 263769407231564
[junit4] 2> 1404170 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:50723_solr] added at times [263769407231564], now=263769407283870
[junit4] 2> 1404170 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"efe599d2164cT37a4fcbxg5ho5tnjdbev0dwy",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":263769407231564,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263769407231564],
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1404170 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 1404171 INFO (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1404171 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"efe599d2164cT37a4fcbxg5ho5tnjdbev0dwy",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":263769407231564,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263769407231564],
[junit4] 2> "_enqueue_time_":263769407565902,
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1404171 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger1
[junit4] 2> 1404173 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 1404173 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 1404173 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2
ms for event id=efe599d2164cT37a4fcbxg5ho5tnjdbev0dwy
[junit4] 2> 1409174 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1409174 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1409174 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 1409175 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1409175 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:50723_solr at time 263774412319505
[junit4] 2> 1409175 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:50723_solr] added at times [263774412319505], now=263774412371873
[junit4] 2> 1409175 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"efe6c425ab11T37a4fcbxg5ho5tnjdbev0dx0",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":263774412319505,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263774412319505],
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1409175 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 1409176 INFO (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1409176 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"efe6c425ab11T37a4fcbxg5ho5tnjdbev0dx0",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":263774412319505,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263774412319505],
[junit4] 2> "_enqueue_time_":263774412546284,
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1409176 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1518358117826000000 current time = 1518358122831000000
[junit4] 2> real diff: 5005000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 1409176 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger2
[junit4] 2> 1409178 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 1409178 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 1409178 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2
ms for event id=efe6c425ab11T37a4fcbxg5ho5tnjdbev0dx0
[junit4] 2> 1409182 INFO (qtp571970206-17241) [n:127.0.0.1:50666_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> 1409184 INFO (qtp1584501771-17315) [n:127.0.0.1:50707_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> 1409186 INFO (qtp1799640029-17339) [n:127.0.0.1:50723_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> 1409186 DEBUG (qtp571970206-17248) [n:127.0.0.1:50666_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1409186 INFO (qtp571970206-17248) [n:127.0.0.1:50666_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 1409191 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 1409192 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409192 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1409192 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409193 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409193 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1409193 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 1409195 INFO (qtp571970206-17250) [n:127.0.0.1:50666_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> 1409196 INFO
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1409197 INFO (qtp1584501771-17315) [n:127.0.0.1:50707_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> 1409197 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 1409198 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 1409199 INFO (qtp1799640029-17339) [n:127.0.0.1:50723_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> 1409199 DEBUG (qtp1584501771-17320) [n:127.0.0.1:50707_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1409200 INFO (qtp1584501771-17320) [n:127.0.0.1:50707_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 1409200 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 1409201 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409201 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1409202 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409202 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409202 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 1409203 DEBUG
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:50723_solr, 127.0.0.1:50666_solr, 127.0.0.1:50707_solr]
[junit4] 2> 1409203 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 1409207 INFO
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1409208 DEBUG
(OverseerAutoScalingTriggerThread-72074879465684998-127.0.0.1:50666_solr-n_0000000001)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 1409208 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.AbstractConnector Stopped
ServerConnector@4e19aef5{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1409209 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=218083778
[junit4] 2> 1409209 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1409209 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@58889df9: rootName =
solr_50723, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@46f0683d
[junit4] 2> 1409210 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 1409216 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 1409216 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@473e650: rootName =
solr_50723, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@4c723e36
[junit4] 2> 1409221 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 1409221 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@31aef74d: rootName =
solr_50723, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@61967348
[junit4] 2> 1409223 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:50723_solr
[junit4] 2> 1409225 INFO
(zkCallback-5998-thread-1-processing-n:127.0.0.1:50723_solr)
[n:127.0.0.1:50723_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1409225 INFO (zkCallback-5980-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 1409225 INFO
(zkCallback-5988-thread-1-processing-n:127.0.0.1:50707_solr)
[n:127.0.0.1:50707_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1409225 INFO
(zkCallback-5970-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1409226 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 1409226 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1409228 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@f0f5699{/solr,null,UNAVAILABLE}
[junit4] 2> 1409228 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.e.j.s.session Stopped scavenging
[junit4] 2> 1410202 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 1410202 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:50723_solr
[junit4] 2> 1410202 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:50723_solr]
[junit4] 2> 1410202 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"efe70162be00T37a4fcbxg5ho5tnjdbev0dx2",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":263775439732224,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263775439732224],
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1410202 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 1410203 INFO (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1410203 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"efe70162be00T37a4fcbxg5ho5tnjdbev0dx2",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":263775439732224,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263775439732224],
[junit4] 2> "_enqueue_time_":263775439930754,
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1410203 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger1
[junit4] 2> 1410210 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 1410210 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 1410211 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 1410211 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 1410211 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 7
ms for event id=efe70162be00T37a4fcbxg5ho5tnjdbev0dx2
[junit4] 2> 1415211 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-1)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:50723_solr
[junit4] 2> 1415211 DEBUG (ScheduledTrigger-5744-thread-4)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:50723_solr]
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-3)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"efe82c02fcd4T37a4fcbxg5ho5tnjdbev0dx4",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":263780449844436,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263780449844436],
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1415212 DEBUG (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 1415213 INFO (ScheduledTrigger-5744-thread-2)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1415213 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"efe82c02fcd4T37a4fcbxg5ho5tnjdbev0dx4",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":263780449844436,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[263780449844436],
[junit4] 2> "_enqueue_time_":263780450169448,
[junit4] 2> "nodeNames":["127.0.0.1:50723_solr"]}}
[junit4] 2> 1415213 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1518358123858000000 current time = 1518358128868000000
[junit4] 2> real diff: 5010000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 1415213 INFO
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger2
[junit4] 2> 1415213 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[41E1348A3C1B7E92]) [
] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 1415217 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 1415217 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 1415217 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 1415218 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 1415218 DEBUG
(AutoscalingActionExecutor-5745-thread-1-processing-n:127.0.0.1:50666_solr)
[n:127.0.0.1:50666_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 4
ms for event id=efe82c02fcd4T37a4fcbxg5ho5tnjdbev0dx4
[junit4] 2> 1415229 INFO (TEST-TriggerIntegrationTest.testNodeMarker
[...truncated too long message...]
0.0.1:53255_solr-n_0000000000) [n:127.0.0.1:53255_solr ] o.a.s.c.Overseer
Overseer Loop exiting : 127.0.0.1:53255_solr
[junit4] 2> 2167600 DEBUG (jetty-closer-4038-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 2167600 WARN
(OverseerAutoScalingTriggerThread-72074927922937864-127.0.0.1:53255_solr-n_0000000000)
[n:127.0.0.1:53255_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2167603 INFO (jetty-closer-4038-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@447d25bd{/solr,null,UNAVAILABLE}
[junit4] 2> 2167603 INFO (jetty-closer-4038-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2167604 INFO
(zkCallback-4064-thread-3-processing-n:127.0.0.1:53257_solr)
[n:127.0.0.1:53257_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53257_solr
[junit4] 2> 2167633 INFO (coreCloseExecutor-7741-thread-2)
[n:127.0.0.1:53283_solr c:.system s:shard1 r:core_node8
x:.system_shard1_replica_n7] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=1111196567
[junit4] 2> 2167634 INFO (coreCloseExecutor-7740-thread-1)
[n:127.0.0.1:53257_solr c:AutoscalingHistoryHandlerTest_collection s:shard1
r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.AutoscalingHistoryHandlerTest_collection.shard1.leader,
tag=1952024119
[junit4] 2> 2167637 INFO
(zkCallback-4083-thread-1-processing-n:127.0.0.1:53283_solr)
[n:127.0.0.1:53283_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:53283_solr
[junit4] 2> 2167638 INFO (jetty-closer-4038-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@165abf32{/solr,null,UNAVAILABLE}
[junit4] 2> 2167639 INFO (jetty-closer-4038-thread-2) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2169143 INFO (jetty-closer-4038-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4d315b7b{/solr,null,UNAVAILABLE}
[junit4] 2> 2169143 INFO (jetty-closer-4038-thread-3) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2169145 ERROR
(SUITE-AutoscalingHistoryHandlerTest-seed#[41E1348A3C1B7E92]-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> 2169145 INFO
(SUITE-AutoscalingHistoryHandlerTest-seed#[41E1348A3C1B7E92]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:53252 53252
[junit4] 2> 2169165 INFO (Thread-3271) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:53252 53252
[junit4] 2> 2169322 WARN (Thread-3271) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/collections/.system/terms/shard1
[junit4] 2> 18
/solr/collections/AutoscalingHistoryHandlerTest_collection/terms/shard1
[junit4] 2> 13 /solr/aliases.json
[junit4] 2> 13 /solr/clusterprops.json
[junit4] 2> 5 /solr/configs/.system
[junit4] 2> 5 /solr/configs/.system/managed-schema
[junit4] 2> 4 /solr/security.json
[junit4] 2> 4
/solr/configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/managed-schema
[junit4] 2> 4
/solr/configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 66 /solr/collections/.system/state.json
[junit4] 2> 43
/solr/collections/AutoscalingHistoryHandlerTest_collection/state.json
[junit4] 2> 13 /solr/clusterstate.json
[junit4] 2> 2
/solr/overseer_elect/election/72074927922937864-127.0.0.1:53255_solr-n_0000000000
[junit4] 2> 2
/solr/collections/AutoscalingHistoryHandlerTest_collection/leader_elect/shard1/election/72074927922937865-core_node5-n_0000000000
[junit4] 2> 2
/solr/collections/.system/leader_elect/shard1/election/72074927922937865-core_node6-n_0000000001
[junit4] 2> 2
/solr/collections/AutoscalingHistoryHandlerTest_collection/leader_elect/shard1/election/72074927922937864-core_node6-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 13 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_41E1348A3C1B7E92-001
[junit4] 2> Feb 11, 2018 2:21:22 PM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70),
sim=RandomSimilarity(queryNorm=true): {}, locale=ee-GH,
timezone=America/Miquelon
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9
(64-bit)/cpus=3,threads=1,free=283230216,total=519569408
[junit4] 2> NOTE: All tests run in this JVM:
[ChaosMonkeyNothingIsSafeTest, TestSearchPerf, DisMaxRequestHandlerTest,
CoreAdminRequestStatusTest, TestLegacyFieldReuse, TestShortCircuitedRequests,
ShowFileRequestHandlerTest, CollectionsAPIDistributedZkTest, TestSchemaManager,
TestClusterProperties, TestSchemaSimilarityResource,
LeaderFailoverAfterPartitionTest, CursorMarkTest,
TestFieldTypeCollectionResource, SolrCloudExampleTest, SortByFunctionTest,
HLLSerializationTest, TestWriterPerf, ZkFailoverTest,
HdfsRestartWhileUpdatingTest, TestSolrConfigHandlerConcurrent,
TestTestInjection, BasicAuthIntegrationTest, TestLRUCache,
TestEmbeddedSolrServerConstructors, TestStressReorder, ResponseBuilderTest,
TestDynamicFieldCollectionResource, JvmMetricsTest,
DefaultValueUpdateProcessorTest, HttpPartitionOnCommitTest,
TestLuceneIndexBackCompat, TestRandomFaceting, TestImplicitCoreProperties,
DistributedIntervalFacetingTest, TestDistribStateManager, ShardRoutingTest,
SolrShardReporterTest, TestSolrDeletionPolicy2, TestWordDelimiterFilterFactory,
TestComplexPhraseQParserPlugin, InfoHandlerTest, IndexBasedSpellCheckerTest,
TestDocumentBuilder, TestAtomicUpdateErrorCases, SolrSlf4jReporterTest,
ShardSplitTest, TestNodeAddedTrigger, AssignTest, SuggestComponentTest,
TestRebalanceLeaders, TestDistributedGrouping,
AsyncCallRequestStatusResponseTest, SchemaApiFailureTest,
HighlighterConfigTest, DistribDocExpirationUpdateProcessorTest,
DocExpirationUpdateProcessorFactoryTest, OverseerStatusTest,
TestStressUserVersions, TestCollationFieldDocValues,
TestUnifiedSolrHighlighter, TestLeaderElectionZkExpiry, JavabinLoaderTest,
TestReplicaProperties, DistributedQueueTest, TestCollectionAPI,
BlockJoinFacetRandomTest, UninvertDocValuesMergePolicyTest, DistanceUnitsTest,
TestLegacyTerms, TestSimpleQParserPlugin, TestJsonFacets, TimeZoneUtilsTest,
TestManagedStopFilterFactory, GraphQueryTest, HDFSCollectionsAPITest,
DeleteReplicaTest, TestFastLRUCache, TestSolrFieldCacheBean,
TestImpersonationWithHadoopAuth, ResponseHeaderTest, QueryParsingTest,
TestFieldCacheVsDocValues, DistributedFacetSimpleRefinementLongTailTest,
TestZkAclsWithHadoopAuth, TestReloadDeadlock, ReturnFieldsTest,
TestNonDefinedSimilarityFactory, TestNamedUpdateProcessors,
TestGraphMLResponseWriter, FacetPivotSmallTest, TestUpdate,
CollectionTooManyReplicasTest, TestSimpleTrackingShardHandler,
TestLMJelinekMercerSimilarityFactory, PKIAuthenticationIntegrationTest,
DebugComponentTest, TolerantUpdateProcessorTest, TestCloudInspectUtil,
TestSolrCloudWithKerberosAlt, TestCollapseQParserPlugin, TestMacroExpander,
ImplicitSnitchTest, RestartWhileUpdatingTest, RequestHandlersTest,
MinimalSchemaTest, HdfsThreadLeakTest, TestPHPSerializedResponseWriter,
TestConfig, ClusterStateTest, TestSolrCoreSnapshots, PeerSyncReplicationTest,
CustomHighlightComponentTest, TestCoreBackup, ResponseLogComponentTest,
TestBadConfig, TestFuzzyAnalyzedSuggestions, UpdateParamsTest,
ClassificationUpdateProcessorFactoryTest, SubstringBytesRefFilterTest,
TestScoreJoinQPScore, TestSkipOverseerOperations,
DeleteLastCustomShardedReplicaTest, RulesTest, SolrMetricReporterTest,
TestClassicSimilarityFactory, TestNestedDocsSort, TestPolicyCloud,
TestSubQueryTransformer, CleanupOldIndexTest, DeleteStatusTest,
BufferStoreTest, ClusterStateUpdateTest, SharedFSAutoReplicaFailoverTest,
PeerSyncWithIndexFingerprintCachingTest, TestHdfsUpdateLog,
RegexBoostProcessorTest, TestReRankQParserPlugin, TestJettySolrRunner,
CustomCollectionTest, TestLockTree, EchoParamsTest,
TestBackupRepositoryFactory, SpatialHeatmapFacetsTest, TestConfigSetImmutable,
TestTriggerIntegration, CdcrBidirectionalTest,
TestSha256AuthenticationProvider, HdfsDirectoryFactoryTest,
TestPayloadScoreQParserPlugin, TestHdfsCloudBackupRestore,
TestPKIAuthenticationPlugin, SimplePostToolTest, TestDistributedSearch,
TestSolr4Spatial, ZkControllerTest, TestCodecSupport, TestOrdValues,
TestManagedSchemaThreadSafety, ReplicaListTransformerTest, TestDistribIDF,
ReplaceNodeTest, TestIntervalFaceting, SpellCheckComponentTest,
TestExclusionRuleCollectionAccess, TestDistribDocBasedVersion,
TestMaxTokenLenTokenizer, TestBlobHandler, TestApiFramework,
TestNumericTokenStream, TestAnalyzedSuggestions,
ManagedSchemaRoundRobinCloudTest, BasicFunctionalityTest,
SpellCheckCollatorTest, ChaosMonkeySafeLeaderTest, TestSortableTextField,
TestReversedWildcardFilterFactory, TestSort, TestPolicyCloud, TestInitQParser,
SparseHLLTest, TestAuthenticationFramework, TestFieldSortValues,
ConfigureRecoveryStrategyTest, TestCryptoKeys, AutoscalingHistoryHandlerTest]
[junit4] Completed [395/775 (2!)] on J1 in 41.02s, 1 test, 1 failure <<<
FAILURES!
[...truncated 42360 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]