Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2334/
2 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTrigger
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at
__randomizedtesting.SeedInfo.seed([176FB296A721E7F1:13911B849DEB656B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTrigger(TriggerIntegrationTest.java:520)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.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([176FB296A721E7F1:7A93166B1D6918F6]: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:244)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 12464 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> Creating dataDir:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/init-core-data-001
[junit4] 2> 240225 WARN
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 240225 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 240226 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 240227 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 240227 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001
[junit4] 2> 240228 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 240228 INFO (Thread-4956) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 240228 INFO (Thread-4956) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 240255 ERROR (Thread-4956) [ ] 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> 240328 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:44675
[junit4] 2> 240347 INFO (zkConnectionManagerCallback-3656-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240368 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 240369 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 240370 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 240370 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 240370 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 240370 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@93b048f{/solr,null,AVAILABLE}
[junit4] 2> 240372 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 240372 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 240372 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 240372 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@50b4db5d{/solr,null,AVAILABLE}
[junit4] 2> 240373 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@277e6979{SSL,[ssl,
http/1.1]}{127.0.0.1:42352}
[junit4] 2> 240373 INFO (jetty-launcher-3653-thread-2) [ ]
o.e.j.s.Server Started @242806ms
[junit4] 2> 240373 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=42352}
[junit4] 2> 240374 ERROR (jetty-launcher-3653-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 240374 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 240374 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 240374 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 240374 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-16T02:43:32.286Z
[junit4] 2> 240375 INFO (zkConnectionManagerCallback-3658-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240376 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@b48eb5d{SSL,[ssl,
http/1.1]}{127.0.0.1:45443}
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.e.j.s.Server Started @242811ms
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=45443}
[junit4] 2> 240379 ERROR (jetty-launcher-3653-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 240379 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-16T02:43:32.291Z
[junit4] 2> 240380 INFO (zkConnectionManagerCallback-3660-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240381 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 240391 INFO (jetty-launcher-3653-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44675/solr
[junit4] 2> 240392 INFO (zkConnectionManagerCallback-3664-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240395 INFO
(zkConnectionManagerCallback-3666-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240413 INFO (jetty-launcher-3653-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44675/solr
[junit4] 2> 240414 INFO (zkConnectionManagerCallback-3671-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240436 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid
0x10040c159160005, likely client has closed socket
[junit4] 2> 240455 INFO
(zkConnectionManagerCallback-3673-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240464 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 240464 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 240465 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:45443_solr
[junit4] 2> 240465 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42352_solr
[junit4] 2> 240466 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.Overseer Overseer
(id=72128793205407748-127.0.0.1:45443_solr-n_0000000000) starting
[junit4] 2> 240488 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 240506 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 240539 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 240547 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 240547 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:42352_solr]
[junit4] 2> 240547 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 240547 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 240548 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45443_solr
[junit4] 2> 240551 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42352.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240555 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 240555 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 240559 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42352.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240559 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42352.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240561 INFO (jetty-launcher-3653-thread-2)
[n:127.0.0.1:42352_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001/node2/.
[junit4] 2> 240561 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 240561 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 240561 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 240618 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45443.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240625 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45443.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240625 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45443.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240626 INFO (jetty-launcher-3653-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001/node1/.
[junit4] 2> 240649 INFO (zkConnectionManagerCallback-3678-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240652 INFO (zkConnectionManagerCallback-3682-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240653 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 240654 INFO
(SUITE-TriggerIntegrationTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44675/solr ready
[junit4] 2> 240675 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 240676 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 240676 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 240676 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 240679 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 240682 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 240683 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 240762 INFO (qtp1469920545-12408) [n:127.0.0.1:42352_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> 240772 INFO (qtp807364362-12396) [n:127.0.0.1:45443_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> 240773 DEBUG (qtp807364362-12399) [n:127.0.0.1:45443_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 240776 INFO (qtp807364362-12399) [n:127.0.0.1:45443_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=61
[junit4] 2> 240777 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 240791 INFO (qtp1469920545-12410) [n:127.0.0.1:42352_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> 240793 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 240793 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 240793 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 240794 INFO (qtp807364362-12402) [n:127.0.0.1:45443_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> 240795 DEBUG (qtp807364362-12401) [n:127.0.0.1:45443_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 240797 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 240797 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 240797 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 240797 INFO (qtp807364362-12401) [n:127.0.0.1:45443_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=19
[junit4] 2> 240798 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 240798 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 240797 INFO
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 240801 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 240803 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 3
[junit4] 2> 240803 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 240804 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 240804 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 240806 INFO
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 240807 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 240811 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 240811 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 240811 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 240811 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 240815 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 240815 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 240815 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 240816 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@3d53e91d{/solr,null,AVAILABLE}
[junit4] 2> 240816 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.AbstractConnector Started ServerConnector@71a65f18{SSL,[ssl,
http/1.1]}{127.0.0.1:46353}
[junit4] 2> 240816 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.Server Started @243249ms
[junit4] 2> 240816 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=46353}
[junit4] 2> 240817 ERROR
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 240821 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 240821 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 240821 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 240821 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-16T02:43:32.733Z
[junit4] 2> 240839 INFO (zkConnectionManagerCallback-3684-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240839 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 240856 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44675/solr
[junit4] 2> 240857 INFO (zkConnectionManagerCallback-3688-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240861 INFO
(zkConnectionManagerCallback-3690-thread-1-processing-n:127.0.0.1:46353_solr)
[n:127.0.0.1:46353_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 240866 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 240867 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 240869 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:46353_solr
[junit4] 2> 240875 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 240875 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 240896 INFO
(zkCallback-3689-thread-1-processing-n:127.0.0.1:46353_solr)
[n:127.0.0.1:46353_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 240900 INFO (zkCallback-3681-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 240922 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46353.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240932 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46353.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240932 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_46353.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 240933 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1])
[n:127.0.0.1:46353_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001/node3/.
[junit4] 2> 241806 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 241806 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 241806 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:46353_solr at time 1086414655836625
[junit4] 2> 241806 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:46353_solr] added at times [1086414655836625], now=1086414656018532
[junit4] 2> 241807 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc169fa3d1d1T9u0opf0f5256b4dtigtgvo5tu",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":1086414655836625,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086414655836625],
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 241807 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 241810 INFO (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 241817 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc169fa3d1d1T9u0opf0f5256b4dtigtgvo5tu",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":1086414655836625,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086414655836625],
[junit4] 2> "_enqueue_time_":1086414656820644,
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 241817 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger1
[junit4] 2> 241820 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 241820 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 241820 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 3
ms for event id=3dc169fa3d1d1T9u0opf0f5256b4dtigtgvo5tu
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:46353_solr at time 1086419670536213
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:46353_solr] added at times [1086419670536213], now=1086419670571905
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc17ca8a1015T9u0opf0f5256b4dtigtgvo5tw",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":1086419670536213,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086419670536213],
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 246821 DEBUG (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 246822 INFO (ScheduledTrigger-1317-thread-2)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 246822 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc17ca8a1015T9u0opf0f5256b4dtigtgvo5tw",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":1086419670536213,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086419670536213],
[junit4] 2> "_enqueue_time_":1086419670772464,
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 246823 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1518749013729000000 current time = 1518749018734000000
[junit4] 2> real diff: 5005000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 246823 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger2
[junit4] 2> 246823 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 246823 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 246823 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=3dc17ca8a1015T9u0opf0f5256b4dtigtgvo5tw
[junit4] 2> 246829 INFO (qtp1469920545-12408) [n:127.0.0.1:42352_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> 246832 INFO (qtp807364362-12399) [n:127.0.0.1:45443_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> 246845 INFO (qtp1012556657-12463) [n:127.0.0.1:46353_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> 246846 DEBUG (qtp1469920545-12411) [n:127.0.0.1:42352_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 246846 INFO (qtp1469920545-12411) [n:127.0.0.1:42352_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=20
[junit4] 2> 246846 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 246847 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246847 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 246847 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246848 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246848 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 246848 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 246850 INFO
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 246851 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 246851 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 246853 INFO (qtp1469920545-12411) [n:127.0.0.1:42352_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> 246855 INFO (qtp807364362-12396) [n:127.0.0.1:45443_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> 246858 INFO (qtp1012556657-12464) [n:127.0.0.1:46353_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> 246858 DEBUG (qtp1012556657-12466) [n:127.0.0.1:46353_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 246860 INFO (qtp1012556657-12466) [n:127.0.0.1:46353_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=11
[junit4] 2> 246860 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 246860 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246861 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 246861 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246861 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246861 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_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> 246861 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:46353_solr, 127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 246861 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 246863 INFO
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 246863 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 246864 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 246865 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.AbstractConnector Stopped ServerConnector@71a65f18{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 246865 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=776516565
[junit4] 2> 246866 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 246866 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@5738b7a7: rootName =
solr_46353, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@26d20848
[junit4] 2> 246872 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 246872 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@653e8b09: rootName =
solr_46353, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@26dc27d3
[junit4] 2> 246876 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 246876 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7c7730a: rootName =
solr_46353, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@22e3a7d0
[junit4] 2> 246877 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:46353_solr
[junit4] 2> 246878 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 246878 INFO (zkCallback-3681-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 246878 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 246879 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 246879 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 246879 INFO
(zkCallback-3689-thread-1-processing-n:127.0.0.1:46353_solr)
[n:127.0.0.1:46353_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 246895 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@3d53e91d{/solr,null,UNAVAILABLE}
[junit4] 2> 246895 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.e.j.s.session Stopped scavenging
[junit4] 2> 247856 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 247856 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:46353_solr
[junit4] 2> 247856 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:46353_solr]
[junit4] 2> 247856 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc18083dcd0dT9u0opf0f5256b4dtigtgvo5ty",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":1086420705725709,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086420705725709],
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 247856 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 247857 INFO (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 247857 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc18083dcd0dT9u0opf0f5256b4dtigtgvo5ty",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":1086420705725709,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086420705725709],
[junit4] 2> "_enqueue_time_":1086420706087051,
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 247858 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger1
[junit4] 2> 247858 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 247858 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 247858 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 247858 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 247859 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=3dc18083dcd0dT9u0opf0f5256b4dtigtgvo5ty
[junit4] 2> 252859 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 252859 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:46353_solr
[junit4] 2> 252859 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:46353_solr]
[junit4] 2> 252859 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc19326a4a5aT9u0opf0f5256b4dtigtgvo5u0",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":1086425708251738,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086425708251738],
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 252859 DEBUG (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 252860 INFO (ScheduledTrigger-1317-thread-4)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 252860 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc19326a4a5aT9u0opf0f5256b4dtigtgvo5u0",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":1086425708251738,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086425708251738],
[junit4] 2> "_enqueue_time_":1086425708482490,
[junit4] 2> "nodeNames":["127.0.0.1:46353_solr"]}}
[junit4] 2> 252860 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1518749019770000000 current time = 1518749024772000000
[junit4] 2> real diff: 5002000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 252860 INFO
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger2
[junit4] 2> 252860 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[176FB296A721E7F1]) [
] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 252862 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 252862 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 252862 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 252862 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 252862 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2
ms for event id=3dc19326a4a5aT9u0opf0f5256b4dtigtgvo5u0
[junit4] 2> 252891 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testListeners
[junit4] 2> 252892 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 252892 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 252892 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 7
[junit4] 2> 252897 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 252897 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 252897 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 252902 INFO (qtp1469920545-12412) [n:127.0.0.1:42352_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> 252906 INFO (qtp807364362-12401) [n:127.0.0.1:45443_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> 252906 DEBUG (qtp1469920545-12410) [n:127.0.0.1:42352_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 252907 INFO (qtp1469920545-12410) [n:127.0.0.1:42352_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 252907 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 252907 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 252907 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction},
{name=test1,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}],
enabled=true}
[junit4] 2> 252908 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 252908 INFO
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 252913 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 252914 INFO (qtp1469920545-12408) [n:127.0.0.1:42352_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> 252914 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 252914 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 252914 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 252916 INFO (qtp807364362-12396) [n:127.0.0.1:45443_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> 252916 DEBUG (qtp1469920545-12411) [n:127.0.0.1:42352_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 252917 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 252917 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 252917 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction},
{name=test1,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}],
enabled=true}
[junit4] 2> 252917 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 252917 INFO (qtp1469920545-12411) [n:127.0.0.1:42352_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 252918 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 252918 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 252919 INFO (qtp1469920545-12412) [n:127.0.0.1:42352_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> 252920 INFO (qtp807364362-12401) [n:127.0.0.1:45443_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> 252921 DEBUG (qtp1469920545-12410) [n:127.0.0.1:42352_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 252921 INFO (qtp1469920545-12410) [n:127.0.0.1:42352_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 252922 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 252922 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42352_solr, 127.0.0.1:45443_solr]
[junit4] 2> 252922 DEBUG
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerL instantiated with properties: {event=nodeAdded, waitFor=3,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction},
{name=test1,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestDummyAction}],
enabled=true}
[junit4] 2> 252922 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 252923 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 252923 DEBUG
(OverseerAutoScalingTriggerThread-72128793205407748-127.0.0.1:45443_solr-n_0000000000)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 252924 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 252967 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 252967 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 252967 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 252975 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@48adafca{/solr,null,AVAILABLE}
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@6f6a81ac{SSL,[ssl,
http/1.1]}{127.0.0.1:37242}
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.Server Started @255408ms
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=37242}
[junit4] 2> 252976 ERROR
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 252976 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-16T02:43:44.888Z
[junit4] 2> 253007 INFO (zkConnectionManagerCallback-3694-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 253007 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 253018 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44675/solr
[junit4] 2> 253025 INFO (zkConnectionManagerCallback-3698-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 253028 INFO
(zkConnectionManagerCallback-3700-thread-1-processing-n:127.0.0.1:37242_solr)
[n:127.0.0.1:37242_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 253033 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 253038 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 253047 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37242_solr
[junit4] 2> 253048 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 253048 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 253048 INFO (zkCallback-3681-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 253060 INFO
(zkCallback-3699-thread-1-processing-n:127.0.0.1:37242_solr)
[n:127.0.0.1:37242_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 253109 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37242.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 253119 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37242.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 253119 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37242.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 253120 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:37242_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001/node4/.
[junit4] 2> 253915 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 253915 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 253915 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:37242_solr at time 1086426764955882
[junit4] 2> 254916 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 254916 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 255917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 255917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 256917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 256917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 256917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerL firing registered processor for nodes:
[127.0.0.1:37242_solr] added at times [1086426764955882], now=1086429766635772
[junit4] 2> 256917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc19716650eaT9u0opf0f5256b4dtigtgvo5u2",
[junit4] 2> "source":"node_added_triggerL",
[junit4] 2> "eventTime":1086426764955882,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086426764955882],
[junit4] 2> "nodeNames":["127.0.0.1:37242_solr"]}}
[junit4] 2> 256917 DEBUG (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_triggerL]
[junit4] 2> 256918 INFO (ScheduledTrigger-1317-thread-1)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 256919 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc19716650eaT9u0opf0f5256b4dtigtgvo5u2",
[junit4] 2> "source":"node_added_triggerL",
[junit4] 2> "eventTime":1086426764955882,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086426764955882],
[junit4] 2> "_enqueue_time_":1086429766854159,
[junit4] 2> "nodeNames":["127.0.0.1:37242_solr"]}}
[junit4] 2> 256923 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_triggerL after 5000ms
[junit4] 2> 256923 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 4
ms for event id=3dc19716650eaT9u0opf0f5256b4dtigtgvo5u2
[junit4] 2> 258924 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-21T14:27:37-07:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 258926 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 258926 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 258926 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 258926 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@57fa5dc4{/solr,null,AVAILABLE}
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@67b86901{SSL,[ssl,
http/1.1]}{127.0.0.1:42334}
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.e.j.s.Server Started @261359ms
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=42334}
[junit4] 2> 258927 ERROR
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 258927 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-16T02:43:50.839Z
[junit4] 2> 258929 INFO (zkConnectionManagerCallback-3704-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 258929 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 258939 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44675/solr
[junit4] 2> 258940 INFO (zkConnectionManagerCallback-3708-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 258947 INFO
(zkConnectionManagerCallback-3710-thread-1-processing-n:127.0.0.1:42334_solr)
[n:127.0.0.1:42334_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 258953 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 258955 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 258956 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42334_solr
[junit4] 2> 258958 INFO
(zkCallback-3672-thread-1-processing-n:127.0.0.1:42352_solr)
[n:127.0.0.1:42352_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 258958 INFO
(zkCallback-3699-thread-1-processing-n:127.0.0.1:37242_solr)
[n:127.0.0.1:37242_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 258958 INFO (zkCallback-3681-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 258959 INFO
(zkCallback-3709-thread-1-processing-n:127.0.0.1:42334_solr)
[n:127.0.0.1:42334_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 258959 INFO
(zkCallback-3665-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 259014 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42334.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 259023 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42334.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 259023 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42334.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@79a76b4d
[junit4] 2> 259025 INFO
(TEST-TriggerIntegrationTest.testListeners-seed#[176FB296A721E7F1])
[n:127.0.0.1:42334_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_176FB296A721E7F1-001/tempDir-001/node5/.
[junit4] 2> 261925 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 261925 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 261925 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:42334_solr at time 1086434774308499
[junit4] 2> 262926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 262926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 263926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 263926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 264926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerL
[junit4] 2> 264926 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 264927 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerL firing registered processor for nodes:
[127.0.0.1:42334_solr] added at times [1086434774308499], now=1086437776101056
[junit4] 2> 264927 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"3dc1b4ecb5693T9u0opf0f5256b4dtigtgvo5u4",
[junit4] 2> "source":"node_added_triggerL",
[junit4] 2> "eventTime":1086434774308499,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086434774308499],
[junit4] 2> "nodeNames":["127.0.0.1:42334_solr"]}}
[junit4] 2> 264927 DEBUG (ScheduledTrigger-1317-thread-3)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_triggerL]
[junit4] 2> 264928 DEBUG
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"3dc1b4ecb5693T9u0opf0f5256b4dtigtgvo5u4",
[junit4] 2> "source":"node_added_triggerL",
[junit4] 2> "eventTime":1086434774308499,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086434774308499],
[junit4] 2> "_enqueue_time_":1086437776320355,
[junit4] 2> "nodeNames":["127.0.0.1:42334_solr"]}}
[junit4] 2> 264928 WARN
(AutoscalingActionExecutor-1318-thread-1-processing-n:127.0.0.1:45443_solr)
[n:127.0.0.1:45443_solr ] o.a.s.c.a.ScheduledTriggers Exception executing
actions
[junit4] 2> java.lang.Exception: Error executing action: test1 for trigger
event: {
[junit4] 2> "id":"3dc1b4ecb5693T9u0opf0f5256b4dtigtgvo5u4",
[junit4] 2> "source":"node_added_triggerL",
[junit4] 2> "eventTime":1086434774308499,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1086434774308499],
[junit4] 2> "_enqueue_time_":1086437776320355,
[junit4] 2> "nodeNames":["127.0.0.1:42334_solr"]}}
[junit4] 2> at
org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:302)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thr
[...truncated too long message...]
tions/AutoscalingHistoryHandlerTest_collection/state.json] for collection
[AutoscalingHistoryHandlerTest_collection] has occurred - updating... (live
nodes size: [0])
[junit4] 2> 574389 INFO
(zkCallback-1249-thread-3-processing-n:127.0.0.1:35602_solr)
[n:127.0.0.1:35602_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for
collection [AutoscalingHistoryHandlerTest_collection] has occurred -
updating... (live nodes size: [0])
[junit4] 2> 574389 INFO
(zkCallback-1249-thread-1-processing-n:127.0.0.1:35602_solr)
[n:127.0.0.1:35602_solr ] o.a.s.c.c.ZkStateReader A cluster state change:
[WatchedEvent state:SyncConnected type:NodeDataChanged
path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for
collection [AutoscalingHistoryHandlerTest_collection] has occurred -
updating... (live nodes size: [0])
[junit4] 2> 574391 INFO (coreCloseExecutor-2341-thread-2)
[n:127.0.0.1:35602_solr c:.system s:shard1 r:core_node6
x:.system_shard1_replica_n4] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=1775683927
[junit4] 2> 574419 INFO (coreCloseExecutor-2342-thread-2)
[n:127.0.0.1:33420_solr c:.system s:shard1 r:core_node5
x:.system_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=638889817
[junit4] 2> 574429 INFO (jetty-closer-1225-thread-2) [ ]
o.a.s.c.Overseer Overseer
(id=72128814129807368-127.0.0.1:35602_solr-n_0000000000) closing
[junit4] 2> 574430 INFO
(OverseerStateUpdate-72128814129807368-127.0.0.1:35602_solr-n_0000000000)
[n:127.0.0.1:35602_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:35602_solr
[junit4] 2> 574441 INFO (coreCloseExecutor-2343-thread-1)
[n:127.0.0.1:34945_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=1387524303
[junit4] 2> 574449 WARN
(OverseerAutoScalingTriggerThread-72128814129807368-127.0.0.1:35602_solr-n_0000000000)
[n:127.0.0.1:35602_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 574450 DEBUG (jetty-closer-1225-thread-2) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 574452 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid
0x10040c638470008, likely client has closed socket
[junit4] 2> 574468 INFO
(zkCallback-1248-thread-2-processing-n:127.0.0.1:34945_solr)
[n:127.0.0.1:34945_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:34945_solr
[junit4] 2> 574467 INFO (coreCloseExecutor-2343-thread-2)
[n:127.0.0.1:34945_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.core..system.shard1.replica_n1, tag=1991975050
[junit4] 2> 574469 INFO (coreCloseExecutor-2343-thread-2)
[n:127.0.0.1:34945_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@34d23c9b: rootName =
solr_34945, domain = solr.core..system.shard1.replica_n1, service url = null,
agent id = null] for registry solr.core..system.shard1.replica_n1 /
com.codahale.metrics.MetricRegistry@714f015e
[junit4] 2> 574482 INFO (jetty-closer-1225-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@603ad0bf{/solr,null,UNAVAILABLE}
[junit4] 2> 574484 INFO (jetty-closer-1225-thread-2) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 574490 INFO (jetty-closer-1225-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@148847b1{/solr,null,UNAVAILABLE}
[junit4] 2> 574497 INFO (jetty-closer-1225-thread-3) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 574500 INFO (coreCloseExecutor-2343-thread-2)
[n:127.0.0.1:34945_solr c:.system s:shard1 r:core_node3
x:.system_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric reporters
for registry=solr.collection..system.shard1.leader, tag=1991975050
[junit4] 2> 574523 INFO (jetty-closer-1225-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4d18f027{/solr,null,UNAVAILABLE}
[junit4] 2> 574525 INFO (jetty-closer-1225-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 574526 ERROR
(SUITE-AutoscalingHistoryHandlerTest-seed#[176FB296A721E7F1]-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> 574526 INFO
(SUITE-AutoscalingHistoryHandlerTest-seed#[176FB296A721E7F1]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:34930 34930
[junit4] 2> 574819 INFO (Thread-1553) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:34930 34930
[junit4] 2> 574820 WARN (Thread-1553) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/aliases.json
[junit4] 2> 11 /solr/clusterprops.json
[junit4] 2> 9
/solr/collections/AutoscalingHistoryHandlerTest_collection/terms/shard1
[junit4] 2> 9 /solr/collections/.system/terms/shard1
[junit4] 2> 4 /solr/security.json
[junit4] 2> 3 /solr/configs/.system
[junit4] 2> 3
/solr/configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/managed-schema
[junit4] 2> 3
/solr/configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED
[junit4] 2> 3 /solr/configs/.system/managed-schema
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 28
/solr/collections/AutoscalingHistoryHandlerTest_collection/state.json
[junit4] 2> 25 /solr/collections/.system/state.json
[junit4] 2> 11 /solr/clusterstate.json
[junit4] 2> 2
/solr/collections/.system/leader_elect/shard1/election/72128814129807369-core_node3-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 11 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_176FB296A721E7F1-001
[junit4] 2> Feb 16, 2018 2:49:06 AM
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):
{action_s=BlockTreeOrds(blocksize=128),
event.source_s=PostingsFormat(name=MockRandom),
type=BlockTreeOrds(blocksize=128),
before.actions_ss=PostingsFormat(name=MockRandom),
event.property._enqueue_time__ss=BlockTreeOrds(blocksize=128),
after.actions_ss=PostingsFormat(name=Memory),
stage_s=BlockTreeOrds(blocksize=128), event.id_s=FSTOrd50,
event.property.eventTimes_ss=BlockTreeOrds(blocksize=128), source_s=FSTOrd50,
event.type_s=BlockTreeOrds(blocksize=128), id=FSTOrd50,
event.property.nodeNames_ss=BlockTreeOrds(blocksize=128)},
docValues:{_version_=DocValuesFormat(name=Asserting),
event.time_l=DocValuesFormat(name=Asserting),
timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1694,
maxMBSortInHeap=7.959769546510938,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@b0cf341),
locale=es-CR, timezone=Asia/Choibalsan
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation
1.8.0_152 (64-bit)/cpus=4,threads=1,free=265154728,total=525860864
[junit4] 2> NOTE: All tests run in this JVM: [DistributedMLTComponentTest,
AsyncCallRequestStatusResponseTest, TestNestedDocsSort, TestDistributedMap,
TestLegacyFieldCache, CollectionStateFormat2Test, ShardRoutingCustomTest,
LoggingHandlerTest, SSLMigrationTest, TestReloadAndDeleteDocs, SuggesterTest,
SoftAutoCommitTest, TestPerFieldSimilarity, PolyFieldTest,
VMParamsZkACLAndCredentialsProvidersTest, PropertiesRequestHandlerTest,
TestXIncludeConfig, TestFileDictionaryLookup, SolrInfoBeanTest,
HDFSCollectionsAPITest, TestSolr4Spatial, TestFieldSortValues,
SolrCLIZkUtilsTest, HttpSolrCallGetCoreTest, AlternateDirectoryTest,
DistribJoinFromCollectionTest, PeerSyncTest, TestJsonRequest,
TestDistributedGrouping, NodeAddedTriggerTest, TestSolrJ, SchemaApiFailureTest,
SolrGangliaReporterTest, QueryElevationComponentTest,
TestBackupRepositoryFactory, DistributedFacetPivotLargeTest,
TestRuleBasedAuthorizationPlugin, CoreMergeIndexesAdminHandlerTest,
OverseerTaskQueueTest, LeaderInitiatedRecoveryOnShardRestartTest,
SolrIndexMetricsTest, TestSolrCoreSnapshots,
ClassificationUpdateProcessorIntegrationTest, HdfsUnloadDistributedZkTest,
TestTlogReplica, TestRestManager, BlockCacheTest, TestConfigsApi,
RemoteQueryErrorTest, TestTrie, TestSystemIdResolver,
OverseerModifyCollectionTest, HdfsDirectoryTest, TestQueryUtils,
HighlighterTest, TestDistributedStatsComponentCardinality,
SignatureUpdateProcessorFactoryTest, TestElisionMultitermQuery,
TestSolrCloudWithDelegationTokens, OutOfBoxZkACLAndCredentialsProvidersTest,
TestMaxTokenLenTokenizer, TestCryptoKeys, TestPayloadScoreQParserPlugin,
InfixSuggestersTest, TestLegacyField, LargeFieldTest,
TestFuzzyAnalyzedSuggestions, SolrCoreTest, AutoscalingHistoryHandlerTest]
[junit4] Completed [165/777 (2!)] on J1 in 15.78s, 1 test, 1 failure <<<
FAILURES!
[...truncated 50524 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
