Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21357/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([EF5404D2EDA40974:5558335DB24CDF3B]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.junit.Assert.assertNull(Assert.java:562)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1575)
at 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 12336 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/init-core-data-001
[junit4] 2> 833898 WARN
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 833898 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 833899 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 833899 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 833899 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001
[junit4] 2> 833899 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 833899 INFO (Thread-1530) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 833899 INFO (Thread-1530) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 833901 ERROR (Thread-1530) [ ] 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> 833999 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:43231
[junit4] 2> 834001 INFO (zkConnectionManagerCallback-1298-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834002 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from
client sessionid 0x1613787e3bc0000, likely client has closed socket
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:239)
[junit4] 2> at
org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:203)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 834003 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T11:27:37+14:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 834004 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T11:27:37+14:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2a1a568c{/solr,null,AVAILABLE}
[junit4] 2> 834015 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@31316538{/solr,null,AVAILABLE}
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@713e3e13{HTTP/1.1,[http/1.1]}{127.0.0.1:38537}
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@3589a196{HTTP/1.1,[http/1.1]}{127.0.0.1:44423}
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.e.j.s.Server Started @836357ms
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.e.j.s.Server Started @836357ms
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=38537}
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=44423}
[junit4] 2> 834016 ERROR (jetty-launcher-1295-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 834016 ERROR (jetty-launcher-1295-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-27T12:11:48.144Z
[junit4] 2> 834016 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-27T12:11:48.144Z
[junit4] 2> 834020 INFO (zkConnectionManagerCallback-1302-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834020 INFO (zkConnectionManagerCallback-1301-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834020 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 834020 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 834026 INFO (jetty-launcher-1295-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43231/solr
[junit4] 2> 834026 INFO (jetty-launcher-1295-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43231/solr
[junit4] 2> 834027 INFO (zkConnectionManagerCallback-1307-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834027 INFO (zkConnectionManagerCallback-1310-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834029 INFO
(zkConnectionManagerCallback-1314-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834029 INFO
(zkConnectionManagerCallback-1312-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834061 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 834061 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 834062 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:38537_solr
[junit4] 2> 834062 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:44423_solr
[junit4] 2> 834067 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.Overseer Overseer
(id=99421723559723014-127.0.0.1:38537_solr-n_0000000000) starting
[junit4] 2> 834070 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 834072 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 834107 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 834107 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38537_solr
[junit4] 2> 834108 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 834111 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 834111 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 834123 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:38537_solr, 127.0.0.1:44423_solr]
[junit4] 2> 834123 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 834123 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 834124 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44423.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834130 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44423.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834131 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44423.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834132 INFO (jetty-launcher-1295-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001/node1/.
[junit4] 2> 834132 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 834139 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 834140 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 834269 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38537.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834274 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38537.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834275 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38537.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834276 INFO (jetty-launcher-1295-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001/node2/.
[junit4] 2> 834313 INFO (zkConnectionManagerCallback-1320-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834317 INFO (zkConnectionManagerCallback-1324-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834317 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 834318 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43231/solr ready
[junit4] 2> 834333 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTriggerRestoreState
[junit4] 2> 834335 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 834335 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 834336 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 2
[junit4] 2> 834338 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 834338 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 834338 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 834354 INFO (qtp1335300337-6547) [n:127.0.0.1:38537_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> 834357 INFO (qtp662699437-6602) [n:127.0.0.1:44423_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> 834357 DEBUG (qtp662699437-6540) [n:127.0.0.1:44423_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 834358 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 834361 INFO (qtp662699437-6540) [n:127.0.0.1:44423_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 834362 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:38537_solr, 127.0.0.1:44423_solr]
[junit4] 2> 834362 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_restore_trigger instantiated with properties: {event=nodeAdded,
waitFor=5, actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 834362 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 834362 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T11:27:37+14:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 834363 INFO
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 834367 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 834366 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 834367 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 834369 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 834391 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 834391 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 834391 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 834391 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2bb07665{/solr,null,AVAILABLE}
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@411182dc{HTTP/1.1,[http/1.1]}{127.0.0.1:36911}
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.Server Started @836733ms
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=36911}
[junit4] 2> 834392 ERROR
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 8.0.0
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 834392 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-27T12:11:48.520Z
[junit4] 2> 834399 INFO (zkConnectionManagerCallback-1326-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834407 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 834427 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43231/solr
[junit4] 2> 834429 INFO (zkConnectionManagerCallback-1330-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834431 INFO
(zkConnectionManagerCallback-1332-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 834433 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 834437 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 834439 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:36911_solr
[junit4] 2> 834440 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 834440 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 834443 INFO (zkCallback-1323-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 834444 INFO
(zkCallback-1331-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 834518 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36911.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834525 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36911.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834525 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36911.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 834526 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:36911_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001/node3/.
[junit4] 2> 835370 DEBUG (ScheduledTrigger-2259-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 835370 DEBUG (ScheduledTrigger-2259-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 835370 DEBUG (ScheduledTrigger-2259-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:36911_solr at time 348893827354871
[junit4] 2> 836072 INFO (qtp1714290693-6614) [n:127.0.0.1:36911_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> 836073 INFO (qtp1335300337-6554) [n:127.0.0.1:38537_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> 836075 INFO (qtp662699437-6601) [n:127.0.0.1:44423_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> 836075 DEBUG (qtp1714290693-6606) [n:127.0.0.1:36911_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 836075 INFO (qtp1714290693-6606) [n:127.0.0.1:36911_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 836076 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 836076 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36911_solr, 127.0.0.1:38537_solr, 127.0.0.1:44423_solr]
[junit4] 2> 836076 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_restore_trigger instantiated with properties: {event=nodeAdded,
waitFor=0, actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 836076 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 836076 INFO
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 836076 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Adding node from
marker path: 127.0.0.1:36911_solr
[junit4] 2> 836077 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 836077 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_restore_trigger
[junit4] 2> 836077 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 836077 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_restore_trigger firing registered processor for nodes:
[127.0.0.1:36911_solr] added at times [348894533533415], now=348894533869123
[junit4] 2> 836077 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"13d5156bc3ee7T7nfbhpx6oidn61ghcpc5od575",
[junit4] 2> "source":"node_added_restore_trigger",
[junit4] 2> "eventTime":348894533533415,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348894533533415],
[junit4] 2> "nodeNames":["127.0.0.1:36911_solr"]}}
[junit4] 2> 836079 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_restore_trigger]
[junit4] 2> 836080 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 836081 INFO (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 836081 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"13d5156bc3ee7T7nfbhpx6oidn61ghcpc5od575",
[junit4] 2> "source":"node_added_restore_trigger",
[junit4] 2> "eventTime":348894533533415,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348894533533415],
[junit4] 2> "_enqueue_time_":348894536599734,
[junit4] 2> "nodeNames":["127.0.0.1:36911_solr"]}}
[junit4] 2> 836082 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTriggerRestoreState
[junit4] 2> 836085 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_restore_trigger after 5000ms
[junit4] 2> 836086 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 4
ms for event id=13d5156bc3ee7T7nfbhpx6oidn61ghcpc5od575
[junit4] 2> 836101 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 836101 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 5
[junit4] 2> 836101 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 836102 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 836102 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 836102 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 836103 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 836104 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T11:27:37+14:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 836104 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@33d7cc36{/solr,null,AVAILABLE}
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@7282364d{HTTP/1.1,[http/1.1]}{127.0.0.1:38607}
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.Server Started @838446ms
[junit4] 2> 836105 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=38607}
[junit4] 2> 836106 ERROR
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 836106 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 8.0.0
[junit4] 2> 836106 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 836106 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 836106 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-27T12:11:50.234Z
[junit4] 2> 836107 INFO (zkConnectionManagerCallback-1336-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 836108 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 836115 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43231/solr
[junit4] 2> 836129 INFO (zkConnectionManagerCallback-1340-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 836131 INFO
(zkConnectionManagerCallback-1342-thread-1-processing-n:127.0.0.1:38607_solr)
[n:127.0.0.1:38607_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 836134 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 836135 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 836137 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38607_solr
[junit4] 2> 836138 INFO
(zkCallback-1331-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 836138 INFO (zkCallback-1323-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 836138 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 836139 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 836143 INFO
(zkCallback-1341-thread-1-processing-n:127.0.0.1:38607_solr)
[n:127.0.0.1:38607_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 836203 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38607.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 836209 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38607.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 836209 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38607.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 836210 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[n:127.0.0.1:38607_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001/node4/.
[junit4] 2> 836254 INFO (qtp1714290693-6614) [n:127.0.0.1:36911_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> 836255 INFO (qtp1335300337-6552) [n:127.0.0.1:38537_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> 836257 INFO (qtp2085465415-6638) [n:127.0.0.1:38607_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> 836258 INFO (qtp662699437-6549) [n:127.0.0.1:44423_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> 836258 DEBUG (qtp662699437-6544) [n:127.0.0.1:44423_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 836258 INFO (qtp662699437-6544) [n:127.0.0.1:44423_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 836258 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 836259 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:38607_solr, 127.0.0.1:36911_solr, 127.0.0.1:38537_solr,
127.0.0.1:44423_solr]
[junit4] 2> 836259 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 836259 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@7282364d{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 836259 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=45850338
[junit4] 2> 836259 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 836259 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@350e2f17: rootName =
solr_38607, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@76db4820
[junit4] 2> 836260 INFO
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 836261 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 836262 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 836262 DEBUG (ScheduledTrigger-2259-thread-2)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 4
[junit4] 2> 836267 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 836267 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@206de462: rootName =
solr_38607, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@4fbb609f
[junit4] 2> 836272 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 836272 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@68ecc3ee: rootName =
solr_38607, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@5448ae76
[junit4] 2> 836273 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:38607_solr
[junit4] 2> 836273 INFO
(zkCallback-1331-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 836273 INFO (zkCallback-1323-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 836274 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 836274 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 836274 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 836274 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 836274 INFO
(zkCallback-1341-thread-1-processing-n:127.0.0.1:38607_solr)
[n:127.0.0.1:38607_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 837263 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 837263 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:38607_solr
[junit4] 2> 837775 WARN
(zkCallback-1341-thread-1-processing-n:127.0.0.1:38607_solr)
[n:127.0.0.1:38607_solr ] o.a.s.c.ZkController Unable to register nodeLost
path for 127.0.0.1:38607_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:38607_solr
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:364)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:364)
[junit4] 2> at
org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:879)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:704)
[junit4] 2> at
java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:268)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 837776 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@33d7cc36{/solr,null,UNAVAILABLE}
[junit4] 2> 837776 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 838264 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 839264 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 839281 INFO (qtp1714290693-6613) [n:127.0.0.1:36911_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> 839283 INFO (qtp1335300337-6548) [n:127.0.0.1:38537_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> 839284 INFO (qtp662699437-6546) [n:127.0.0.1:44423_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> 839285 DEBUG (qtp1714290693-6611) [n:127.0.0.1:36911_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 839285 INFO (qtp1714290693-6611) [n:127.0.0.1:36911_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 839285 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 839285 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36911_solr, 127.0.0.1:38537_solr, 127.0.0.1:44423_solr]
[junit4] 2> 839285 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 839286 INFO
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 839286 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from
marker path: 127.0.0.1:38607_solr
[junit4] 2> 839286 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 839286 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 839286 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:38607_solr]
[junit4] 2> 839286 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 839286 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"13d521609390fT7nfbhpx6oidn61ghcpc5od577",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":348897743026447,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348897743026447],
[junit4] 2> "nodeNames":["127.0.0.1:38607_solr"]}}
[junit4] 2> 839286 DEBUG (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_restore_trigger]
[junit4] 2> 839287 INFO (ScheduledTrigger-2259-thread-1)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 839287 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"13d521609390fT7nfbhpx6oidn61ghcpc5od577",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":348897743026447,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348897743026447],
[junit4] 2> "_enqueue_time_":348897743493732,
[junit4] 2> "nodeNames":["127.0.0.1:38607_solr"]}}
[junit4] 2> 839287 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[EF5404D2EDA40974])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState
[junit4] 2> 839287 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_restore_trigger after 5000ms
[junit4] 2> 839287 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=13d521609390fT7nfbhpx6oidn61ghcpc5od577
[junit4] 2> 839300 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
[junit4] 2> 839300 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 8
[junit4] 2> 839300 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 839300 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 839301 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 839301 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 839301 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 839302 INFO (qtp1714290693-6614) [n:127.0.0.1:36911_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 839305 INFO (qtp1714290693-6614) [n:127.0.0.1:36911_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 839307 INFO (qtp1714290693-6633) [n:127.0.0.1:36911_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> 839307 INFO (qtp1335300337-6552) [n:127.0.0.1:38537_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> 839308 INFO (qtp662699437-6544) [n:127.0.0.1:44423_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> 839308 DEBUG (qtp1714290693-6611) [n:127.0.0.1:36911_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 839308 INFO (qtp1714290693-6611) [n:127.0.0.1:36911_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 839309 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 839309 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 839309 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36911_solr, 127.0.0.1:38537_solr, 127.0.0.1:44423_solr]
[junit4] 2> 839309 DEBUG
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerEQ instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 839309 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 839309 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 839310 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 839310 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 839310 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerEQ
[junit4] 2> 839310 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 839310 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T11:27:37+14:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 839313 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 839313 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 839313 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 839313 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@3c692da9{/solr,null,AVAILABLE}
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@5a97d668{HTTP/1.1,[http/1.1]}{127.0.0.1:45915}
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.Server Started @841655ms
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=45915}
[junit4] 2> 839314 ERROR
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 839314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-27T12:11:53.442Z
[junit4] 2> 839315 INFO (zkConnectionManagerCallback-1346-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 839316 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 839321 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43231/solr
[junit4] 2> 839321 INFO (zkConnectionManagerCallback-1350-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 839323 INFO
(zkConnectionManagerCallback-1352-thread-1-processing-n:127.0.0.1:45915_solr)
[n:127.0.0.1:45915_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 839325 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 839326 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 839327 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:45915_solr
[junit4] 2> 839327 INFO
(zkCallback-1331-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 839327 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 839327 INFO (zkCallback-1323-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 839327 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 839328 INFO
(zkCallback-1351-thread-1-processing-n:127.0.0.1:45915_solr)
[n:127.0.0.1:45915_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 839379 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45915.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 839385 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45915.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 839385 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_45915.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@358aacff
[junit4] 2> 839386 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974])
[n:127.0.0.1:45915_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001/tempDir-001/node5/.
[junit4] 2> 840310 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerEQ
[junit4] 2> 840310 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 840310 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:45915_solr at time 348898767610945
[junit4] 2> 841303 INFO
(OverseerCollectionConfigSetProcessor-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 841311 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerEQ
[junit4] 2> 841311 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 4
[junit4] 2> 841311 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerEQ firing registered processor for nodes:
[127.0.0.1:45915_solr] added at times [348898767610945], now=348899768389158
[junit4] 2> 841311 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"]}}
[junit4] 2> 841311 DEBUG (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_triggerEQ]
[junit4] 2> 841312 INFO (ScheduledTrigger-2259-thread-3)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 841312 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "_enqueue_time_":348899768537986,
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"]}}
[junit4] 2> 841313 INFO
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "_enqueue_time_":348899768537986,
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"]}}
[junit4] 2> 841313 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@713e3e13{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 841314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=672204301
[junit4] 2> 841314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 841314 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@68a8752f: rootName =
solr_38537, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@1fc1961f
[junit4] 2> 841318 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 841318 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1d18e646: rootName =
solr_38537, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@4fbb609f
[junit4] 2> 841321 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 841321 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@6e9c80fe: rootName =
solr_38537, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@5448ae76
[junit4] 2> 841322 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:38537_solr
[junit4] 2> 841322 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 841322 INFO (zkCallback-1323-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 841322 INFO
(zkCallback-1331-thread-1-processing-n:127.0.0.1:36911_solr)
[n:127.0.0.1:36911_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 841322 INFO
(zkCallback-1351-thread-1-processing-n:127.0.0.1:45915_solr)
[n:127.0.0.1:45915_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 841322 INFO
(zkCallback-1311-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 841322 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 841322 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 841322 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.Overseer Overseer
(id=99421723559723014-127.0.0.1:38537_solr-n_0000000000) closing
[junit4] 2> 841322 INFO
(OverseerStateUpdate-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:38537_solr
[junit4] 2> 841322 WARN
(OverseerAutoScalingTriggerThread-99421723559723014-127.0.0.1:38537_solr-n_0000000000)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 841323 DEBUG
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 841323 WARN
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers Exception executing
actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException:
ScheduledTrigger node_added_triggerEQ has been closed.
[junit4] 2> at
org.apache.solr.cloud.autoscaling.ScheduledTriggers$ScheduledTrigger.dequeue(ScheduledTriggers.java:525)
[junit4] 2> at
org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:309)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 841323 DEBUG
(AutoscalingActionExecutor-2260-thread-1-processing-n:127.0.0.1:38537_solr)
[n:127.0.0.1:38537_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 10
ms for event id=13d52531b2441T7nfbhpx6oidn61ghcpc5od579
[junit4] 2> 841323 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@2a1a568c{/solr,null,UNAVAILABLE}
[junit4] 2> 841323 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:44423_solr
[junit4] 2> 841324 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 841324 INFO
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.Overseer Overseer
(id=99421723559723013-127.0.0.1:44423_solr-n_0000000001) starting
[junit4] 2> 841326 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 841326 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 841326 INFO
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 841326 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:45915_solr, 127.0.0.1:36911_solr, 127.0.0.1:44423_solr]
[junit4] 2> 841327 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerEQ instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 841327 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:45915_solr, 127.0.0.1:36911_solr, 127.0.0.1:44423_solr]
[junit4] 2> 841327 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion -1
[junit4] 2> 841327 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 841328 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 841328 DEBUG (ScheduledTrigger-2287-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 841328 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 841328 DEBUG (ScheduledTrigger-2287-thread-2)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "_dequeue_time_":348899785154985,
[junit4] 2> "_enqueue_time_":348899768537986,
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 841328 DEBUG (ScheduledTrigger-2287-thread-2)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[.auto_add_replicas, node_added_triggerEQ]
[junit4] 2> 841329 INFO (ScheduledTrigger-2287-thread-2)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 841329 DEBUG
(AutoscalingActionExecutor-2288-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "_dequeue_time_":348899785154985,
[junit4] 2> "_enqueue_time_":348899768537986,
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 841329 INFO
(AutoscalingActionExecutor-2288-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: {
[junit4] 2> "id":"13d52531b2441T7nfbhpx6oidn61ghcpc5od579",
[junit4] 2> "source":"node_added_triggerEQ",
[junit4] 2> "eventTime":348898767610945,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[348898767610945],
[junit4] 2> "_dequeue_time_":348899785154985,
[junit4] 2> "_enqueue_time_":348899768537986,
[junit4] 2> "nodeNames":["127.0.0.1:45915_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 841329 DEBUG (ScheduledTrigger-2287-thread-2)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerEQ
[junit4] 2> 841329 DEBUG (ScheduledTrigger-2287-thread-2)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 841330 DEBUG
(AutoscalingActionExecutor-2288-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
.auto_add_replicas after 5000ms
[junit4] 2> 841330 DEBUG
(AutoscalingActionExecutor-2288-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_triggerEQ after 5000ms
[junit4] 2> 841330 DEBUG
(AutoscalingActionExecutor-2288-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=13d52531b2441T7nfbhpx6oidn61ghcpc5od579
[junit4] 2> 846324 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[EF5404D2EDA40974]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
[junit4] 2> 846330 DEBUG (ScheduledTrigger-2287-thread-1)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 846330 DEBUG (ScheduledTrigger-2287-thread-3)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerEQ
[junit4] 2> 846331 DEBUG (ScheduledTrigger-2287-thread-3)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 846339 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testSetProperties
[junit4] 2> 846340 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 11
[junit4] 2> 846340 DEBUG
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 11
[junit4] 2> 846340 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 11
[junit4] 2> 846341 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 846341 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 846341 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 847343 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerScheduleDelaySeconds from: 1 to: 4
[junit4] 2> 855345 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerScheduleDelaySeconds from: 4 to: 1
[junit4] 2> 865348 DEBUG
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property:
triggerCorePoolSize from: 4 to: 6
[junit4] 2> 875352 INFO
(TEST-TriggerIntegrationTest.testSetProperties-seed#[EF5404D2EDA40974]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testSetProperties
[junit4] 2> 875362 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[EF5404D2EDA40974]) [
] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 875362 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[EF5404D2EDA40974]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 12
[junit4] 2> 875363 DEBUG
(zkCallback-1313-thread-1-processing-n:127.0.0.1:44423_solr)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 12
[junit4] 2> 875363 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 12
[junit4] 2> 875363 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 875363 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 875363 DEBUG
(OverseerAutoScalingTriggerThread-99421723559723013-127.0.0.1:44423_solr-n_0000000001)
[n:127.0.0.1:44423_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 12, lastZnodeVersion 12
[junit4] 2> 875366 INFO (qtp1714290693-6613) [n:127.0.0.1:36911_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> 875368 INFO (qtp662699437-6546) [n:127.0.0.1:44423_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> 875369 INFO (qtp833908056-6665) [n:127.0.0.1:45915_solr ]
o.a.s
[...truncated too long message...]
eplica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@4876738e: rootName =
solr_43157, domain = solr.core.testMetricTrigger.shard1.replica_n1, service url
= null, agent id = null] for registry
solr.core.testMetricTrigger.shard1.replica_n1 /
com.codahale.metrics.MetricRegistry@38f8e066
[junit4] 2> 1025883 INFO
(zkCallback-1431-thread-3-processing-n:127.0.0.1:41439_solr)
[n:127.0.0.1:41439_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (11) -> (0)
[junit4] 2> 1025887 INFO (jetty-closer-1296-thread-4) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@65241b83{/solr,null,UNAVAILABLE}
[junit4] 2> 1025887 INFO (jetty-closer-1296-thread-9) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@65a029d2{/solr,null,UNAVAILABLE}
[junit4] 2> 1025888 INFO (jetty-closer-1296-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@583bada8{/solr,null,UNAVAILABLE}
[junit4] 2> 1025888 INFO (jetty-closer-1296-thread-9) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025888 INFO (jetty-closer-1296-thread-4) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025888 INFO (jetty-closer-1296-thread-8) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025889 INFO (jetty-closer-1296-thread-6) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025895 INFO (coreCloseExecutor-2459-thread-1)
[n:127.0.0.1:39187_solr c:collection1 s:shard1 r:core_node6
x:collection1_shard1_replica_n5] o.a.s.c.SolrCore
[collection1_shard1_replica_n5] CLOSING SolrCore
org.apache.solr.core.SolrCore@1ea96612
[junit4] 2> 1025895 INFO (coreCloseExecutor-2459-thread-1)
[n:127.0.0.1:39187_solr c:collection1 s:shard1 r:core_node6
x:collection1_shard1_replica_n5] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.collection1.shard1.replica_n5, tag=514418194
[junit4] 2> 1025895 INFO (coreCloseExecutor-2459-thread-1)
[n:127.0.0.1:39187_solr c:collection1 s:shard1 r:core_node6
x:collection1_shard1_replica_n5] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7b2b613: rootName =
solr_39187, domain = solr.core.collection1.shard1.replica_n5, service url =
null, agent id = null] for registry solr.core.collection1.shard1.replica_n5 /
com.codahale.metrics.MetricRegistry@54586763
[junit4] 2> 1025899 INFO
(zkCallback-1371-thread-4-processing-n:127.0.0.1:43157_solr)
[n:127.0.0.1:43157_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (10) -> (0)
[junit4] 2> 1025903 INFO (coreCloseExecutor-2458-thread-1)
[n:127.0.0.1:41439_solr c:collection1 s:shard1 r:core_node4
x:collection1_shard1_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.collection1.shard1.leader, tag=1194109886
[junit4] 2> 1025913 INFO (jetty-closer-1296-thread-11) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@2b4ce695{/solr,null,UNAVAILABLE}
[junit4] 2> 1025913 INFO (coreCloseExecutor-2448-thread-2)
[n:127.0.0.1:43067_solr c:testMetricTrigger s:shard2 r:core_node4
x:testMetricTrigger_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testMetricTrigger.shard2.leader,
tag=543920703
[junit4] 2> 1025914 INFO (coreCloseExecutor-2457-thread-1)
[n:127.0.0.1:43157_solr c:testMetricTrigger s:shard1 r:core_node3
x:testMetricTrigger_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testMetricTrigger.shard1.leader,
tag=925291836
[junit4] 2> 1025918 INFO (jetty-closer-1296-thread-11) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025923 INFO (coreCloseExecutor-2459-thread-1)
[n:127.0.0.1:39187_solr c:collection1 s:shard1 r:core_node6
x:collection1_shard1_replica_n5] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.collection1.shard1.leader, tag=514418194
[junit4] 2> 1025928 INFO (jetty-closer-1296-thread-7) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@34ed3b52{/solr,null,UNAVAILABLE}
[junit4] 2> 1025929 INFO (jetty-closer-1296-thread-5) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@119d9b07{/solr,null,UNAVAILABLE}
[junit4] 2> 1025929 INFO (jetty-closer-1296-thread-7) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025929 INFO (jetty-closer-1296-thread-5) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025931 INFO (jetty-closer-1296-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=99421723559723031-127.0.0.1:43157_solr-n_0000000006) closing
[junit4] 2> 1025931 INFO
(OverseerStateUpdate-99421723559723031-127.0.0.1:43157_solr-n_0000000006)
[n:127.0.0.1:43157_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:43157_solr
[junit4] 2> 1025931 WARN
(OverseerAutoScalingTriggerThread-99421723559723031-127.0.0.1:43157_solr-n_0000000006)
[n:127.0.0.1:43157_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1025932 DEBUG (jetty-closer-1296-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1025933 INFO (jetty-closer-1296-thread-2) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1fb8cbf5{/solr,null,UNAVAILABLE}
[junit4] 2> 1025933 INFO (jetty-closer-1296-thread-2) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025934 INFO (jetty-closer-1296-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1332e491{/solr,null,UNAVAILABLE}
[junit4] 2> 1025934 INFO (jetty-closer-1296-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1025940 ERROR
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-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> 1025940 INFO
(SUITE-TriggerIntegrationTest-seed#[EF5404D2EDA40974]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:43231 43231
[junit4] 2> 1031052 INFO (Thread-1530) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:43231 43231
[junit4] 2> 1031052 WARN (Thread-1530) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/clusterprops.json
[junit4] 2> 22 /solr/aliases.json
[junit4] 2> 21 /solr/security.json
[junit4] 2> 6 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 64 /solr/collections/collection1/state.json
[junit4] 2> 22 /solr/clusterstate.json
[junit4] 2> 13 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 6 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/99421723559723049-127.0.0.1:41439_solr-n_0000000012
[junit4] 2> 3
/solr/overseer_elect/election/99421723559723034-127.0.0.1:39187_solr-n_0000000007
[junit4] 2> 3
/solr/overseer_elect/election/99421723559723064-127.0.0.1:36055_solr-n_0000000017
[junit4] 2> 2
/solr/overseer_elect/election/99421723559723019-127.0.0.1:36911_solr-n_0000000002
[junit4] 2> 2
/solr/overseer_elect/election/99421723559723058-127.0.0.1:33607_solr-n_0000000015
[junit4] 2> 2
/solr/overseer_elect/election/99421723559723043-127.0.0.1:43067_solr-n_0000000010
[junit4] 2> 2
/solr/collections/collection1/leader_elect/shard1/election/99421723559723034-core_node6-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/live_nodes
[junit4] 2> 22 /solr/collections
[junit4] 2> 6 /solr/overseer/queue-work
[junit4] 2> 6 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 6 /solr/overseer/queue
[junit4] 2> 6 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/node_lost_triggerMR
[junit4] 2> 2 /solr/autoscaling/events/node_added_triggerCTOOR
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_EF5404D2EDA40974-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{id=FSTOrd50, x_s=PostingsFormat(name=Direct)}, docValues:{},
maxPointsInLeafNode=1866, maxMBSortInHeap=6.287361949327676,
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@63c75cf3),
locale=hi, timezone=Asia/Rangoon
[junit4] 2> NOTE: Linux 4.13.0-31-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=8,threads=1,free=85002120,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [ConnectionReuseTest,
AnalyticsMergeStrategyTest, TestJmxIntegration, TestQuerySenderListener,
TestCollectionsAPIViaSolrCloudCluster, SimpleMLTQParserTest,
TestMiniSolrCloudClusterSSL, TestDistribStateManager, ConvertedLegacyTest,
TestMultiWordSynonyms, TestCloudNestedDocsSort, DateRangeFieldTest,
NumberUtilsTest, TestPKIAuthenticationPlugin,
DistributedFacetPivotLongTailTest, TestSolrCoreParser, BasicDistributedZk2Test,
RegexBytesRefFilterTest, StatelessScriptUpdateProcessorFactoryTest,
TestBadConfig, BlobRepositoryCloudTest, ShardSplitTest, TestExactStatsCache,
ManagedSchemaRoundRobinCloudTest, DocValuesMultiTest,
TestManagedSchemaThreadSafety, TestHdfsBackupRestoreCore,
BaseCdcrDistributedZkTest, SpatialFilterTest, TestSolrDeletionPolicy2,
MoreLikeThisHandlerTest, TestCloudRecovery, WrapperMergePolicyFactoryTest,
CleanupOldIndexTest, TriggerIntegrationTest]
[junit4] Completed [212/770 (1!)] on J2 in 197.23s, 14 tests, 1 failure <<<
FAILURES!
[...truncated 49962 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
