Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Linux/1101/
Java: 64bit/jdk1.8.0_144 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeMarkersRegistration
Error Message:
Path /autoscaling/nodeAdded/127.0.0.1:36645_solr wasn't created
Stack Trace:
java.lang.AssertionError: Path /autoscaling/nodeAdded/127.0.0.1:36645_solr
wasn't created
at
__randomizedtesting.SeedInfo.seed([999AE2567DAB0BB6:81206A5A739EC659]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeMarkersRegistration(TriggerIntegrationTest.java:936)
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 13736 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 2256617 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/init-core-data-001
[junit4] 2> 2256618 WARN
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=21 numCloses=21
[junit4] 2> 2256618 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2256620 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2256621 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001
[junit4] 2> 2256621 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2256621 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2256621 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 2256623 ERROR (Thread-7673) [ ] 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> 2256721 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:33871
[junit4] 2> 2256723 INFO (zkConnectionManagerCallback-7976-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256729 INFO (jetty-launcher-7973-thread-2) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2256758 INFO (jetty-launcher-7973-thread-1) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2256759 INFO (jetty-launcher-7973-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6be54420{/solr,null,AVAILABLE}
[junit4] 2> 2256759 INFO (jetty-launcher-7973-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6cbd0135{/solr,null,AVAILABLE}
[junit4] 2> 2256760 INFO (jetty-launcher-7973-thread-2) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@3d854857{SSL,[ssl,
http/1.1]}{127.0.0.1:34279}
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ]
o.e.j.s.Server Started @2258128ms
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@7d1470d0{SSL,[ssl,
http/1.1]}{127.0.0.1:42069}
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=34279}
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ]
o.e.j.s.Server Started @2258128ms
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=42069}
[junit4] 2> 2256761 ERROR (jetty-launcher-7973-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2256761 ERROR (jetty-launcher-7973-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2256761 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-02T11:07:14.365Z
[junit4] 2> 2256762 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-02T11:07:14.365Z
[junit4] 2> 2256763 INFO (zkConnectionManagerCallback-7980-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256764 INFO (zkConnectionManagerCallback-7979-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256764 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2256764 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2256772 INFO (jetty-launcher-7973-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr
[junit4] 2> 2256772 INFO (jetty-launcher-7973-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr
[junit4] 2> 2256773 INFO (zkConnectionManagerCallback-7986-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256773 INFO (zkConnectionManagerCallback-7988-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256774 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 0x160b68dcbb10004, 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> 2256774 INFO
(zkConnectionManagerCallback-7991-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256774 INFO
(zkConnectionManagerCallback-7992-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:42069_solr
[junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:34279_solr
[junit4] 2> 2256799 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer
(id=99279911926169605-127.0.0.1:42069_solr-n_0000000000) starting
[junit4] 2> 2256799 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2256799 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 2256801 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 2256802 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:42069_solr
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:34279_solr]
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 2256802 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2256802 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2256802 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 2256803 DEBUG (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2256844 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42069.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256845 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34279.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42069.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_42069.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256849 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34279.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34279.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node1/.
[junit4] 2> 2256850 INFO (jetty-launcher-7973-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node2/.
[junit4] 2> 2256872 INFO (zkConnectionManagerCallback-7998-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256874 INFO (zkConnectionManagerCallback-8002-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256874 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2256875 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33871/solr ready
[junit4] 2> 2256881 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 2256881 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 2
[junit4] 2> 2256882 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 2256882 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 2256883 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2256883 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2256883 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 2256884 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2256884 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7ffd6024{/solr,null,AVAILABLE}
[junit4] 2> 2256884 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.AbstractConnector Started ServerConnector@45f1ebce{SSL,[ssl,
http/1.1]}{127.0.0.1:43859}
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.Server Started @2258252ms
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=43859}
[junit4] 2> 2256885 ERROR
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™
version 7.3.0
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2256885 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-02T11:07:14.488Z
[junit4] 2> 2256886 INFO (zkConnectionManagerCallback-8004-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256886 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2256903 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr
[junit4] 2> 2256904 INFO (zkConnectionManagerCallback-8008-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256905 INFO
(zkConnectionManagerCallback-8010-thread-1-processing-n:127.0.0.1:43859_solr)
[n:127.0.0.1:43859_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2256908 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 2256909 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2256909 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:43859_solr
[junit4] 2> 2256910 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2256910 INFO
(zkCallback-8009-thread-1-processing-n:127.0.0.1:43859_solr)
[n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2256913 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2256913 INFO (zkCallback-8001-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2256952 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43859.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256957 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43859.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256957 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43859.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2256958 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:43859_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node3/.
[junit4] 2> 2257013 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2257015 INFO (qtp1653336593-30001) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2257031 INFO (qtp269752659-30045) [n:127.0.0.1:43859_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2257031 DEBUG (qtp1653336593-29993) [n:127.0.0.1:42069_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2257031 INFO (qtp1653336593-29993) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=34
[junit4] 2> 2257031 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 2257032 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:42069_solr, 127.0.0.1:43859_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2257032 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 2257032 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.AbstractConnector Stopped ServerConnector@45f1ebce{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 2257032 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=980382025
[junit4] 2> 2257032 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 2257032 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7b137207: rootName =
solr_43859, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@74433e0d
[junit4] 2> 2257032 INFO
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2257033 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2257033 DEBUG (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 2257033 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 2257037 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 2257037 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1c3d54b1: rootName =
solr_43859, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@13133f0
[junit4] 2> 2257040 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 2257040 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@467bfd1b: rootName =
solr_43859, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@4b15606
[junit4] 2> 2257041 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:43859_solr
[junit4] 2> 2257041 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 2257041 INFO
(zkCallback-8009-thread-1-processing-n:127.0.0.1:43859_solr)
[n:127.0.0.1:43859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2257041 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2257041 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 2257041 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2257041 INFO (zkCallback-8001-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 2257041 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@7ffd6024{/solr,null,UNAVAILABLE}
[junit4] 2> 2258034 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 2
[junit4] 2> 2258034 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:43859_solr
[junit4] 2> 2258544 INFO (qtp524086121-29991) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2258545 INFO (qtp1653336593-29995) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2258545 DEBUG (qtp1653336593-29999) [n:127.0.0.1:42069_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2258546 INFO (qtp1653336593-29999) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 2258546 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 2258547 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:42069_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2258547 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 2258547 INFO
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2258548 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from
marker path: 127.0.0.1:43859_solr
[junit4] 2> 2258549 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 2
[junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:43859_solr]
[junit4] 2> 2258549 DEBUG (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"935c111305629Tajxqea3gpnxlbq48kuywanoea",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":2592378123736617,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592378123736617],
[junit4] 2> "nodeNames":["127.0.0.1:43859_solr"]}}
[junit4] 2> 2258549 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 2258550 INFO (ScheduledTrigger-8227-thread-1)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2258550 DEBUG
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"935c111305629Tajxqea3gpnxlbq48kuywanoea",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":2592378123736617,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592378123736617],
[junit4] 2> "_enqueue_time_":2592378124912904,
[junit4] 2> "nodeNames":["127.0.0.1:43859_solr"]}}
[junit4] 2> 2258551 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[999AE2567DAB0BB6])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState
[junit4] 2> 2258552 DEBUG
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=935c111305629Tajxqea3gpnxlbq48kuywanoea
[junit4] 2> 2258568 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testEventQueue
[junit4] 2> 2258569 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
[junit4] 2> 2258569 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 2258569 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 2258570 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2258570 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2258571 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 2258573 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2258579 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 2258581 INFO (qtp524086121-29990) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2258581 INFO (qtp1653336593-30001) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2258581 DEBUG (qtp1653336593-30000) [n:127.0.0.1:42069_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2258582 INFO (qtp1653336593-30000) [n:127.0.0.1:42069_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 2258582 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 2258582 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 2258583 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:42069_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2258583 DEBUG
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 2258583 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 2258584 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2258585 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2258585 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 2258585 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2258585 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2258586 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2258589 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@650a44f2{/solr,null,AVAILABLE}
[junit4] 2> 2258590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@da1f34d{SSL,[ssl,
http/1.1]}{127.0.0.1:41701}
[junit4] 2> 2258590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.Server Started @2259957ms
[junit4] 2> 2258590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=41701}
[junit4] 2> 2258590 ERROR
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2258590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2258590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2258591 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2258591 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-02T11:07:16.194Z
[junit4] 2> 2258593 INFO (zkConnectionManagerCallback-8014-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2258594 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2258604 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr
[junit4] 2> 2258605 INFO (zkConnectionManagerCallback-8018-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2258608 INFO
(zkConnectionManagerCallback-8020-thread-1-processing-n:127.0.0.1:41701_solr)
[n:127.0.0.1:41701_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2258613 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 2258615 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2258616 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:41701_solr
[junit4] 2> 2258617 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2258617 INFO (zkCallback-8001-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2258617 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2258617 INFO
(zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr)
[n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2258675 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41701.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2258681 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41701.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2258681 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_41701.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2258682 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:41701_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node4/.
[junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2259586 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:41701_solr at time 2592379161614893
[junit4] 2> 2260577 INFO
(OverseerCollectionConfigSetProcessor-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_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> 2260587 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:41701_solr] added at times [2592379161614893], now=2592380162841182
[junit4] 2> 2260587 DEBUG (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}}
[junit4] 2> 2260588 INFO (ScheduledTrigger-8227-thread-2)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2260589 DEBUG
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "_enqueue_time_":2592380163157100,
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}}
[junit4] 2> 2260589 INFO
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "_enqueue_time_":2592380163157100,
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"]}}
[junit4] 2> 2260590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.AbstractConnector Stopped ServerConnector@7d1470d0{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 2260590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=2029564889
[junit4] 2> 2260590 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 2260591 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@11581c65: rootName =
solr_42069, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@100380e
[junit4] 2> 2260600 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 2260600 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@69d9c5c6: rootName =
solr_42069, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@13133f0
[junit4] 2> 2260606 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 2260606 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@423b34d8: rootName =
solr_42069, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@4b15606
[junit4] 2> 2260608 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:42069_solr
[junit4] 2> 2260609 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 2260609 INFO (zkCallback-8001-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 2260609 INFO
(zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr)
[n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2260609 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 2260609 INFO
(zkCallback-7989-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2260609 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2260609 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.Overseer Overseer
(id=99279911926169605-127.0.0.1:42069_solr-n_0000000000) closing
[junit4] 2> 2260610 INFO
(OverseerStateUpdate-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:42069_solr
[junit4] 2> 2260610 WARN
(OverseerAutoScalingTriggerThread-99279911926169605-127.0.0.1:42069_solr-n_0000000000)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2260610 DEBUG
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 2260610 WARN
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers Exception executing
actions
[junit4] 2> org.apache.lucene.store.AlreadyClosedException:
ScheduledTrigger node_added_trigger1 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:337)
[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> 2260611 DEBUG
(AutoscalingActionExecutor-8228-thread-1-processing-n:127.0.0.1:42069_solr)
[n:127.0.0.1:42069_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 22
ms for event id=935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec
[junit4] 2> 2260635 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@6cbd0135{/solr,null,UNAVAILABLE}
[junit4] 2> 2260635 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:34279_solr
[junit4] 2> 2260636 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.Overseer Overseer
(id=99279911926169606-127.0.0.1:34279_solr-n_0000000001) starting
[junit4] 2> 2260640 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 2260641 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 2260641 INFO
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventQueueAction instantiated
[junit4] 2> 2260641 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2260642 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventQueueAction}],
enabled=true}
[junit4] 2> 2260642 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2260642 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion -1
[junit4] 2> 2260642 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 2260643 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2260644 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2260644 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 2260644 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "_dequeue_time_":2592380219582429,
[junit4] 2> "_enqueue_time_":2592380163157100,
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 2260644 INFO (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2260645 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "_dequeue_time_":2592380219582429,
[junit4] 2> "_enqueue_time_":2592380163157100,
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 2260645 INFO
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest -- event: {
[junit4] 2> "id":"935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592379161614893,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592379161614893],
[junit4] 2> "_dequeue_time_":2592380219582429,
[junit4] 2> "_enqueue_time_":2592380163157100,
[junit4] 2> "nodeNames":["127.0.0.1:41701_solr"],
[junit4] 2> "replaying":true}}
[junit4] 2> 2260645 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2260645 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2260646 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=935c14f0d1a2dTajxqea3gpnxlbq48kuywanoec
[junit4] 2> 2261644 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2261646 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2261646 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2262645 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2262647 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2262647 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2263645 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2263647 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2263647 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2264645 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 2264647 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2264647 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2265636 INFO
(TEST-TriggerIntegrationTest.testEventQueue-seed#[999AE2567DAB0BB6]) [ ]
o.a.s.SolrTestCaseJ4 ###Ending testEventQueue
[junit4] 2> 2265642 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 2265643 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 8
[junit4] 2> 2265643 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 2265643 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 2265643 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2265643 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2265644 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 2265647 INFO (qtp524086121-29986) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2265664 INFO (qtp1580809983-30078) [n:127.0.0.1:41701_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2265664 DEBUG (qtp524086121-29991) [n:127.0.0.1:34279_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2265665 INFO (qtp524086121-29991) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=19
[junit4] 2> 2265665 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 2265665 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2265665 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 2265665 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 2265666 INFO (qtp524086121-29987) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2265666 INFO
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2265666 INFO (qtp1580809983-30083) [n:127.0.0.1:41701_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2265666 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2265667 DEBUG (qtp524086121-29990) [n:127.0.0.1:34279_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2265667 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 2265667 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2265667 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2265667 INFO (qtp524086121-29990) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 2265667 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 2265667 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2265667 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 2265667 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2265667 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 2265667 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 2265668 INFO
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2265668 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2265668 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 2265668 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2265668 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 2265668 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2265669 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6c3ce994{/solr,null,AVAILABLE}
[junit4] 2> 2265669 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.e.j.s.AbstractConnector Started ServerConnector@397e370f{SSL,[ssl,
http/1.1]}{127.0.0.1:35953}
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.e.j.s.Server Started @2267037ms
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=35953}
[junit4] 2> 2265670 ERROR
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2265670 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-02T11:07:23.273Z
[junit4] 2> 2265671 INFO (zkConnectionManagerCallback-8024-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2265671 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2265675 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33871/solr
[junit4] 2> 2265676 INFO (zkConnectionManagerCallback-8028-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2265677 INFO
(zkConnectionManagerCallback-8030-thread-1-processing-n:127.0.0.1:35953_solr)
[n:127.0.0.1:35953_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2265678 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 2265679 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2265679 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:35953_solr
[junit4] 2> 2265680 INFO
(zkCallback-8019-thread-1-processing-n:127.0.0.1:41701_solr)
[n:127.0.0.1:41701_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2265680 INFO
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2265680 INFO (zkCallback-8001-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2265680 INFO
(zkCallback-8029-thread-1-processing-n:127.0.0.1:35953_solr)
[n:127.0.0.1:35953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2265716 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_35953.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2265722 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_35953.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2265723 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_35953.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@26cc246
[junit4] 2> 2265723 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[999AE2567DAB0BB6])
[n:127.0.0.1:35953_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001/tempDir-001/node5/.
[junit4] 2> 2266667 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:35953_solr at time 2592386243233988
[junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592386243233988], now=2592386243315937
[junit4] 2> 2266668 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"935c2f52608c4Tajxqea3gpnxlbq48kuywanoef",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592386243233988,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592386243233988],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2266669 INFO (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2266669 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"935c2f52608c4Tajxqea3gpnxlbq48kuywanoef",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":2592386243233988,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592386243233988],
[junit4] 2> "_enqueue_time_":2592386243541197,
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2266669 INFO
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger1
[junit4] 2> 2266671 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=935c2f52608c4Tajxqea3gpnxlbq48kuywanoef
[junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:35953_solr at time 2592387244772636
[junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592387244772636], now=2592387244845377
[junit4] 2> 2267669 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown
period - rejecting event: {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoeh",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2267670 INFO (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2267671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2267671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592387244772636], now=2592388246323729
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2268671 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown
period - rejecting event: {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoej",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592387244772636], now=2592389246831764
[junit4] 2> 2269671 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown
period - rejecting event: {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoek",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2270671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2270671 DEBUG (ScheduledTrigger-8249-thread-1)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592387244772636], now=2592390247296109
[junit4] 2> 2270672 DEBUG (ScheduledTrigger-8249-thread-3)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -------- Cooldown
period - rejecting event: {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoel",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-4)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:35953_solr] added at times [2592387244772636], now=2592391247809781
[junit4] 2> 2271672 DEBUG (ScheduledTrigger-8249-thread-2)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoem",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2271673 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"935c330d84d1cTajxqea3gpnxlbq48kuywanoem",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":2592387244772636,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[2592387244772636],
[junit4] 2> "_enqueue_time_":2592391248118994,
[junit4] 2> "nodeNames":["127.0.0.1:35953_solr"]}}
[junit4] 2> 2271673 INFO
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1514891244272000000 current time = 1514891249276000000
[junit4] 2> real diff: 5004000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 2271674 INFO
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger2
[junit4] 2> 2271674 DEBUG
(AutoscalingActionExecutor-8250-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=935c330d84d1cTajxqea3gpnxlbq48kuywanoem
[junit4] 2> 2271677 INFO (qtp524086121-29986) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2271720 INFO (qtp1114245096-30113) [n:127.0.0.1:35953_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2271722 INFO (qtp1580809983-30084) [n:127.0.0.1:41701_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CORE.coreName&wt=javabin&version=2&group=solr.core} status=0
QTime=0
[junit4] 2> 2271722 DEBUG (qtp524086121-29985) [n:127.0.0.1:34279_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2271723 INFO (qtp524086121-29985) [n:127.0.0.1:34279_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=47
[junit4] 2> 2271723 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 11
[junit4] 2> 2271724 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2271724 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 2271724 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2271725 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:35953_solr, 127.0.0.1:41701_solr, 127.0.0.1:34279_solr]
[junit4] 2> 2271725 DEBUG
(zkCallback-7990-thread-1-processing-n:127.0.0.1:34279_solr)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 instantiated with properties: {event=nodeAdded, waitFor=0,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$ThrottlingTesterAction}],
enabled=true}
[junit4] 2> 2271725 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 11
[junit4] 2> 2271725 INFO
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:34279_solr-n_0000000001)
[n:127.0.0.1:34279_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 2271726 DEBUG
(OverseerAutoScalingTriggerThread-99279911926169606-127.0.0.1:
[...truncated too long message...]
-thread-1) [n:127.0.0.1:43373_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=1121638154
[junit4] 2> 2411640 INFO
(zkCallback-8079-thread-3-processing-n:127.0.0.1:43373_solr)
[n:127.0.0.1:43373_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:43373_solr
[junit4] 2> 2411640 INFO (jetty-closer-7974-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@748df9f5{/solr,null,UNAVAILABLE}
[junit4] 2> 2411640 INFO (jetty-closer-7974-thread-4) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@31d9fa66{/solr,null,UNAVAILABLE}
[junit4] 2> 2411640 WARN
(zkCallback-8112-thread-3-processing-n:127.0.0.1:35603_solr)
[n:127.0.0.1:35603_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2411640 INFO (jetty-closer-7974-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@cd58e77{/solr,null,UNAVAILABLE}
[junit4] 2> 2411640 INFO (jetty-closer-7974-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@46ad49e0{/solr,null,UNAVAILABLE}
[junit4] 2> 2413140 WARN
(zkCallback-8132-thread-3-processing-n:127.0.0.1:37617_solr)
[n:127.0.0.1:37617_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2413140 WARN
(zkCallback-8172-thread-2-processing-n:127.0.0.1:36345_solr)
[n:127.0.0.1:36345_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2413140 INFO (jetty-closer-7974-thread-8) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@5e3e043e{/solr,null,UNAVAILABLE}
[junit4] 2> 2413140 INFO (jetty-closer-7974-thread-11) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@664473c7{/solr,null,UNAVAILABLE}
[junit4] 2> 2413141 ERROR
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-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> 2413141 INFO
(SUITE-TriggerIntegrationTest-seed#[999AE2567DAB0BB6]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:33871 33871
[junit4] 2> 2418203 INFO (Thread-7673) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:33871 33871
[junit4] 2> 2418204 WARN (Thread-7673) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/aliases.json
[junit4] 2> 19 /solr/security.json
[junit4] 2> 3 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 25 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 20 /solr/clusterprops.json
[junit4] 2> 20 /solr/clusterstate.json
[junit4] 2> 5 /solr/autoscaling.json
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169651-127.0.0.1:39477_solr-n_0000000015
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169614-127.0.0.1:41701_solr-n_0000000003
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169606-127.0.0.1:34279_solr-n_0000000001
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169642-127.0.0.1:35603_solr-n_0000000012
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169654-127.0.0.1:41141_solr-n_0000000016
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169623-127.0.0.1:36645_solr-n_0000000006
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169635-127.0.0.1:42793_solr-n_0000000010
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169626-127.0.0.1:42821_solr-n_0000000007
[junit4] 2> 2
/solr/overseer_elect/election/99279911926169648-127.0.0.1:37617_solr-n_0000000014
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 20 /solr/live_nodes
[junit4] 2> 20 /solr/collections
[junit4] 2> 5 /solr/overseer/queue-work
[junit4] 2> 5 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 5 /solr/overseer/queue
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/node_added_trigger
[junit4] 2> 2 /solr/autoscaling/events/node_added_trigger1
[junit4] 2> 2 /solr/autoscaling/events/node_lost_trigger
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-7.x-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.TriggerIntegrationTest_999AE2567DAB0BB6-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70):
{id=BlockTreeOrds(blocksize=128), x_s=PostingsFormat(name=Asserting)},
docValues:{}, maxPointsInLeafNode=1806, maxMBSortInHeap=7.6907611988713445,
sim=RandomSimilarity(queryNorm=false): {}, locale=ms-MY,
timezone=America/Swift_Current
[junit4] 2> NOTE: Linux 4.10.0-40-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=8,threads=1,free=209973408,total=518979584
[junit4] 2> NOTE: All tests run in this JVM:
[TestClassicSimilarityFactory, TestFileDictionaryLookup, LargeFieldTest,
TestLRUCache, TestCoreDiscovery, TestSchemaNameResource, TestDynamicLoading,
IndexSchemaTest, TestImpersonationWithHadoopAuth, IndexBasedSpellCheckerTest,
TestExtendedDismaxParser, TestConfigReload,
LeaderInitiatedRecoveryOnCommitTest, FileBasedSpellCheckerTest,
TestHashPartitioner, TestMiniSolrCloudClusterSSL,
UninvertDocValuesMergePolicyTest, TestHdfsUpdateLog, TestComputePlanAction,
TestQuerySenderListener, TestSchemalessBufferedUpdates, MoveReplicaHDFSTest,
TestCSVResponseWriter, ReplicationFactorTest, TestExportWriter,
RecoveryAfterSoftCommitTest, TestRequestForwarding, TestFieldCache,
SmileWriterTest, DefaultValueUpdateProcessorTest, TimeZoneUtilsTest,
PluginInfoTest, CdcrUpdateLogTest, TestRealTimeGet, TestStressLiveNodes,
TestNestedDocsSort, SegmentsInfoRequestHandlerTest,
TestManagedSchemaThreadSafety, TestSkipOverseerOperations,
TestHdfsCloudBackupRestore, SolrJmxReporterTest,
TestCollectionsAPIViaSolrCloudCluster, TestNumericRangeQuery64, RecoveryZkTest,
BasicDistributedZk2Test, TestLegacyField, UpdateLogTest,
UnloadDistributedZkTest, TestRestManager, HdfsCollectionsAPIDistributedZkTest,
TestCoreContainer, AsyncCallRequestStatusResponseTest, LoggingHandlerTest,
TestDistributedMissingSort, TestInitParams, CollectionReloadTest,
SolrTestCaseJ4Test, TestEmbeddedSolrServerConstructors,
CoreAdminRequestStatusTest, SolrMetricManagerTest, TestRawTransformer,
AnalyticsMergeStrategyTest, TestFunctionQuery, V2StandaloneTest, SuggesterTest,
TestQueryTypes, TestTolerantSearch, ChaosMonkeyNothingIsSafeTest,
ReturnFieldsTest, TestLegacyTerms, RequestLoggingTest, TestReloadDeadlock,
TestTriggerIntegration, DirectSolrSpellCheckerTest, TestConfigOverlay,
TestSubQueryTransformerDistrib, AlternateDirectoryTest,
BlockJoinFacetSimpleTest, TestJavabinTupleStreamParser, MigrateRouteKeyTest,
TestFieldCacheSortRandom, MetricUtilsTest,
UniqFieldsUpdateProcessorFactoryTest, TestShardHandlerFactory,
WordBreakSolrSpellCheckerTest, SuggesterWFSTTest,
TestComplexPhraseLeadingWildcard, CoreAdminHandlerTest,
TestDynamicFieldCollectionResource, TestFieldSortValues, OverseerTest,
SolrGangliaReporterTest, LeaderElectionTest, TestFuzzyAnalyzedSuggestions,
HighlighterTest, HdfsDirectoryFactoryTest,
ClassificationUpdateProcessorIntegrationTest, ConfigSetsAPITest,
SolrCoreCheckLockOnStartupTest, CdcrBootstrapTest, TestSolrDeletionPolicy2,
TestSearchPerf, RuleEngineTest, HttpTriggerListenerTest,
TestPayloadScoreQParserPlugin, PKIAuthenticationIntegrationTest,
MetricsHandlerTest, SystemInfoHandlerTest, TestReplicationHandlerBackup,
TestCharFilters, ZkNodePropsTest, TestSchemaVersionResource,
TestLegacyFieldCache, TestNamedUpdateProcessors,
AtomicUpdateProcessorFactoryTest, TestPullReplica, QueryElevationComponentTest,
TriLevelCompositeIdRoutingTest, HighlighterMaxOffsetTest,
SolrShardReporterTest, TestChildDocTransformer, TestDistributedGrouping,
OpenCloseCoreStressTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest,
TestReplicationHandler, TestZkChroot, ZkCLITest, SimplePostToolTest,
SpellCheckCollatorTest, DocValuesTest, TestWordDelimiterFilterFactory,
DirectUpdateHandlerOptimizeTest, TestRemoteStreaming, DistanceFunctionTest,
SolrInfoBeanTest, DebugComponentTest, DisMaxRequestHandlerTest, TestWriterPerf,
PrimitiveFieldTypeTest, TermsComponentTest, TestValueSourceCache,
MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest,
TestAnalyzedSuggestions, CSVRequestHandlerTest, TestComponentsName,
TestLFUCache, TestBinaryField, MinimalSchemaTest, TestSolrCoreProperties,
DirectSolrConnectionTest, TestLuceneMatchVersion, TestXIncludeConfig,
TestSweetSpotSimilarityFactory, TestLMDirichletSimilarityFactory,
TestIBSimilarityFactory, ScriptEngineTest, PrimUtilsTest,
SpellingQueryConverterTest, RAMDirectoryFactoryTest, SliceStateTest,
FileUtilsTest, CursorPagingTest, TestCursorMarkWithoutUniqueKey,
TestEmbeddedSolrServerAdminHandler, TestEmbeddedSolrServerSchemaAPI,
TestJettySolrRunner, ConnectionReuseTest, AssignBackwardCompatibilityTest,
CollectionsAPISolrJTest, DeleteShardTest, DistributedQueueTest,
HttpPartitionTest, RemoteQueryErrorTest, RestartWhileUpdatingTest,
SSLMigrationTest, SaslZkACLProviderTest, ShardSplitTest,
TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorRandomCloud,
AutoAddReplicasIntegrationTest, TriggerIntegrationTest]
[junit4] Completed [627/764 (1!)] on J2 in 161.67s, 14 tests, 1 failure, 1
skipped <<< FAILURES!
[...truncated 48606 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
