Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21341/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTrigger
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([403A938CC188709D:44C43A9EFB42F207]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeLostTrigger(TriggerIntegrationTest.java:521)
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 12421 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 581045 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-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-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/init-core-data-001
[junit4] 2> 581046 WARN
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 581046 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 581048 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 581049 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001
[junit4] 2> 581049 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 581050 INFO (Thread-1178) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 581050 INFO (Thread-1178) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 581052 ERROR (Thread-1178) [ ] 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> 581150 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:35187
[junit4] 2> 581152 INFO (zkConnectionManagerCallback-1139-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581155 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 0x1612cc52e890000, 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> 581159 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 581159 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 581173 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@626a833{/solr,null,AVAILABLE}
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@255faf2f{/solr,null,AVAILABLE}
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@3f79abd3{SSL,[ssl,
http/1.1]}{127.0.0.1:40859}
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.AbstractConnector Started ServerConnector@430a8ea6{SSL,[ssl,
http/1.1]}{127.0.0.1:36711}
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-2) [ ]
o.e.j.s.Server Started @582756ms
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-1) [ ]
o.e.j.s.Server Started @582756ms
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=40859}
[junit4] 2> 581174 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=36711}
[junit4] 2> 581175 ERROR (jetty-launcher-1136-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 581175 ERROR (jetty-launcher-1136-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-25T10:02:55.621Z
[junit4] 2> 581175 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-25T10:02:55.621Z
[junit4] 2> 581176 INFO (zkConnectionManagerCallback-1142-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581176 INFO (zkConnectionManagerCallback-1143-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581176 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 581176 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 581183 INFO (jetty-launcher-1136-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35187/solr
[junit4] 2> 581184 INFO (jetty-launcher-1136-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35187/solr
[junit4] 2> 581186 INFO (zkConnectionManagerCallback-1148-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581188 INFO (zkConnectionManagerCallback-1151-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581197 INFO
(zkConnectionManagerCallback-1153-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581198 INFO
(zkConnectionManagerCallback-1155-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581242 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 581242 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 581242 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:40859_solr
[junit4] 2> 581242 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:36711_solr
[junit4] 2> 581243 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.Overseer Overseer
(id=99409892179771398-127.0.0.1:40859_solr-n_0000000000) starting
[junit4] 2> 581244 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 581244 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 581254 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 581254 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:40859_solr
[junit4] 2> 581254 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 581254 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr]
[junit4] 2> 581254 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 581255 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 581255 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 581255 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 581257 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 581259 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 581265 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 581350 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40859.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581359 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36711.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581365 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40859.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581365 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40859.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581367 INFO (jetty-launcher-1136-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001/node2/.
[junit4] 2> 581371 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36711.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581371 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_36711.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581372 INFO (jetty-launcher-1136-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001/node1/.
[junit4] 2> 581421 INFO (zkConnectionManagerCallback-1161-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581423 INFO (zkConnectionManagerCallback-1165-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581423 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 581423 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35187/solr ready
[junit4] 2> 581439 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.SolrTestCaseJ4 ###Starting testTriggerThrottling
[junit4] 2> 581440 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 581440 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 581440 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 581449 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 581449 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 581449 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 581501 INFO (qtp1506398012-5393) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 581529 INFO (qtp1865372367-5392) [n:127.0.0.1:40859_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 581529 DEBUG (qtp1506398012-5391) [n:127.0.0.1:36711_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 581530 INFO (qtp1506398012-5391) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=45
[junit4] 2> 581530 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 581534 INFO (qtp1506398012-5385) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 581536 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr]
[junit4] 2> 581536 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 581536 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 581536 INFO (qtp1865372367-5396) [n:127.0.0.1:40859_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 581537 DEBUG (qtp1506398012-5395) [n:127.0.0.1:36711_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 581537 INFO
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 581537 INFO (qtp1506398012-5395) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 581538 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 581538 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr]
[junit4] 2> 581538 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 581538 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr]
[junit4] 2> 581538 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 581538 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 581538 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 3
[junit4] 2> 581540 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 581538 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 581540 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 581541 INFO
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 581541 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 581542 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 581542 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 581549 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 581549 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 581557 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 581557 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 581557 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 581561 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@5ab1d617{/solr,null,AVAILABLE}
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.AbstractConnector Started ServerConnector@36ecb370{SSL,[ssl,
http/1.1]}{127.0.0.1:38373}
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.Server Started @583143ms
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=38373}
[junit4] 2> 581562 ERROR
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version
8.0.0
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 581562 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-25T10:02:56.008Z
[junit4] 2> 581578 INFO (zkConnectionManagerCallback-1167-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581578 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 581585 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35187/solr
[junit4] 2> 581593 INFO (zkConnectionManagerCallback-1171-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581599 INFO
(zkConnectionManagerCallback-1173-thread-1-processing-n:127.0.0.1:38373_solr)
[n:127.0.0.1:38373_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 581601 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 581602 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 581603 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:38373_solr
[junit4] 2> 581604 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 581604 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 581615 INFO (zkCallback-1164-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 581615 INFO
(zkCallback-1172-thread-1-processing-n:127.0.0.1:38373_solr)
[n:127.0.0.1:38373_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 581666 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38373.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581675 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38373.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581675 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_38373.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 581676 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D])
[n:127.0.0.1:38373_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001/node3/.
[junit4] 2> 582543 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 582543 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 582543 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 582543 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:38373_solr at time 168361318636787
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:38373_solr at time 168361318636841
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger1 firing registered processor for nodes:
[127.0.0.1:38373_solr] added at times [168361318636787], now=168361318739318
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:38373_solr] added at times [168361318636841], now=168361318739509
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"991fac975cf3T55tr1r9dih9e70tcshahjf2yg",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":168361318636787,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168361318636787],
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"991fac975d29T55tr1r9dih9e70tcshahjf2yh",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":168361318636841,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168361318636841],
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 582544 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 582544 INFO (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 582545 INFO (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 582545 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"991fac975cf3T55tr1r9dih9e70tcshahjf2yg",
[junit4] 2> "source":"node_added_trigger1",
[junit4] 2> "eventTime":168361318636787,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168361318636787],
[junit4] 2> "_enqueue_time_":168361319371936,
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 582545 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger1
[junit4] 2> 582545 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 582545 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 582545 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=991fac975cf3T55tr1r9dih9e70tcshahjf2yg
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-3)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-3)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger2 firing registered processor for nodes:
[127.0.0.1:38373_solr] added at times [168361318636841], now=168366321165033
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"991fac975d29T55tr1r9dih9e70tcshahjf2yk",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":168361318636841,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168361318636841],
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 587546 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger2, node_added_trigger1]
[junit4] 2> 587547 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"991fac975d29T55tr1r9dih9e70tcshahjf2yk",
[junit4] 2> "source":"node_added_trigger2",
[junit4] 2> "eventTime":168361318636841,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168361318636841],
[junit4] 2> "_enqueue_time_":168366321317419,
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 587547 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1516874576991000000 current time = 1516874581993000000
[junit4] 2> real diff: 5002000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 587547 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_added_trigger2
[junit4] 2> 587547 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 587547 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 587547 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=991fac975d29T55tr1r9dih9e70tcshahjf2yk
[junit4] 2> 587570 INFO (qtp1506398012-5385) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587574 INFO (qtp337025431-5449) [n:127.0.0.1:38373_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587576 INFO (qtp1865372367-5394) [n:127.0.0.1:40859_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587576 DEBUG (qtp337025431-5452) [n:127.0.0.1:38373_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 587577 INFO (qtp337025431-5452) [n:127.0.0.1:38373_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=9
[junit4] 2> 587577 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 587577 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587577 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 587577 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587578 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587578 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 587578 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 587580 INFO (qtp1506398012-5395) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587580 INFO
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 587580 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 587580 DEBUG (ScheduledTrigger-2435-thread-3)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 3
[junit4] 2> 587584 INFO (qtp337025431-5453) [n:127.0.0.1:38373_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587584 INFO (qtp1865372367-5396) [n:127.0.0.1:40859_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 587585 DEBUG (qtp337025431-5454) [n:127.0.0.1:38373_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 587585 INFO (qtp337025431-5454) [n:127.0.0.1:38373_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 587585 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_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> 587586 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40859_solr, 127.0.0.1:38373_solr]
[junit4] 2> 587586 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 587587 INFO
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 587588 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 587588 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 3
[junit4] 2> 587588 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.AbstractConnector Stopped ServerConnector@36ecb370{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 587589 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=220437284
[junit4] 2> 587589 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 587589 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@40e02c7f: rootName =
solr_38373, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@701b2e33
[junit4] 2> 587597 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 587597 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@4a194be0: rootName =
solr_38373, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@53461a0a
[junit4] 2> 587603 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 587603 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@66c56ba6: rootName =
solr_38373, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@15f286a6
[junit4] 2> 587604 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:38373_solr
[junit4] 2> 587604 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 587604 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 587604 INFO (zkCallback-1164-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 587604 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 587604 INFO
(zkCallback-1172-thread-1-processing-n:127.0.0.1:38373_solr)
[n:127.0.0.1:38373_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 587604 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 587605 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@5ab1d617{/solr,null,UNAVAILABLE}
[junit4] 2> 587605 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.e.j.s.session Stopped scavenging
[junit4] 2> 588582 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 588582 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:38373_solr
[junit4] 2> 588582 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:38373_solr]
[junit4] 2> 588582 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"9921148292aeT55tr1r9dih9e70tcshahjf2yl",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":168367357072046,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168367357072046],
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 588582 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 588583 INFO (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 588583 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"9921148292aeT55tr1r9dih9e70tcshahjf2yl",
[junit4] 2> "source":"node_lost_trigger1",
[junit4] 2> "eventTime":168367357072046,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168367357072046],
[junit4] 2> "_enqueue_time_":168367357221525,
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 588583 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger1
[junit4] 2> 588583 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 588583 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 588583 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 588583 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 588584 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=9921148292aeT55tr1r9dih9e70tcshahjf2yl
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger2 with currently live nodes: 2
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger2
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:38373_solr
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-1)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:38373_solr]
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-4)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger1 with currently live nodes: 2
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-3)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger1
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"99223ea28553T55tr1r9dih9e70tcshahjf2yn",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":168372358776147,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168372358776147],
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-3)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 593584 DEBUG (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger2, node_added_trigger2, node_lost_trigger1,
node_added_trigger1]
[junit4] 2> 593584 INFO (ScheduledTrigger-2435-thread-2)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 593584 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"99223ea28553T55tr1r9dih9e70tcshahjf2yn",
[junit4] 2> "source":"node_lost_trigger2",
[junit4] 2> "eventTime":168372358776147,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168372358776147],
[junit4] 2> "_enqueue_time_":168372359028702,
[junit4] 2> "nodeNames":["127.0.0.1:38373_solr"]}}
[junit4] 2> 593584 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest last action at
1516874583029000000 current time = 1516874588030000000
[junit4] 2> real diff: 5001000000
[junit4] 2> min diff: 4998000000
[junit4] 2> 593584 INFO
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.TriggerIntegrationTest action executed
from node_lost_trigger2
[junit4] 2> 593584 INFO
(TEST-TriggerIntegrationTest.testTriggerThrottling-seed#[403A938CC188709D]) [
] o.a.s.SolrTestCaseJ4 ###Ending testTriggerThrottling
[junit4] 2> 593585 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger2 after 5000ms
[junit4] 2> 593585 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger2 after 5000ms
[junit4] 2> 593585 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger1 after 5000ms
[junit4] 2> 593585 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger1 after 5000ms
[junit4] 2> 593585 DEBUG
(AutoscalingActionExecutor-2436-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=99223ea28553T55tr1r9dih9e70tcshahjf2yn
[junit4] 2> 593599 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeMarkersRegistration
[junit4] 2> 593600 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 7
[junit4] 2> 593600 DEBUG
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 593600 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 593601 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 593602 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 593602 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 593603 INFO (qtp1506398012-5391) [n:127.0.0.1:36711_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 593606 INFO (qtp1506398012-5391) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 593608 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 593608 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 593608 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 593608 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 593608 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@35cd07a6{/solr,null,AVAILABLE}
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.AbstractConnector Started ServerConnector@633be32f{SSL,[ssl,
http/1.1]}{127.0.0.1:40041}
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.Server Started @595190ms
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=40041}
[junit4] 2> 593609 ERROR
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 8.0.0
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 593609 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-25T10:03:08.055Z
[junit4] 2> 593610 INFO (zkConnectionManagerCallback-1177-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 593610 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 593615 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35187/solr
[junit4] 2> 593616 INFO (zkConnectionManagerCallback-1181-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 593618 INFO
(zkConnectionManagerCallback-1183-thread-1-processing-n:127.0.0.1:40041_solr)
[n:127.0.0.1:40041_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 593620 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 593621 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 593622 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:40041_solr
[junit4] 2> 593622 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 593622 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 593628 INFO (zkCallback-1164-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 593629 INFO
(zkCallback-1182-thread-1-processing-n:127.0.0.1:40041_solr)
[n:127.0.0.1:40041_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 593686 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40041.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 593696 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40041.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 593697 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_40041.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 593698 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:40041_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001/node4/.
[junit4] 2> 593734 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== KILL OVERSEER 1
[junit4] 2> 593734 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3f79abd3{SSL,[ssl,
http/1.1]}{127.0.0.1:0}
[junit4] 2> 593735 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=348570247
[junit4] 2> 593735 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 593735 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3ff65433: rootName =
solr_40859, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@7159a1b9
[junit4] 2> 593742 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 593742 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@76d59565: rootName =
solr_40859, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@53461a0a
[junit4] 2> 593747 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 593747 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7b9b6af7: rootName =
solr_40859, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@15f286a6
[junit4] 2> 593748 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:40859_solr
[junit4] 2> 593748 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 593748 INFO
(zkCallback-1182-thread-1-processing-n:127.0.0.1:40041_solr)
[n:127.0.0.1:40041_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 593748 INFO (zkCallback-1164-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 593748 INFO
(zkCallback-1154-thread-1-processing-n:127.0.0.1:40859_solr)
[n:127.0.0.1:40859_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 593748 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 593749 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.Overseer Overseer
(id=99409892179771398-127.0.0.1:40859_solr-n_0000000000) closing
[junit4] 2> 593749 INFO
(OverseerStateUpdate-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:40859_solr
[junit4] 2> 593749 WARN
(OverseerAutoScalingTriggerThread-99409892179771398-127.0.0.1:40859_solr-n_0000000000)
[n:127.0.0.1:40859_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 593751 DEBUG
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed
explicitly
[junit4] 2> 593751 INFO
(zkCallback-1152-thread-1-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 593751 INFO
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:36711_solr
[junit4] 2> 593751 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@255faf2f{/solr,null,UNAVAILABLE}
[junit4] 2> 593752 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 593752 INFO
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.Overseer Overseer
(id=99409892179771397-127.0.0.1:36711_solr-n_0000000001) starting
[junit4] 2> 593761 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 593762 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 593762 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 593762 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion -1
[junit4] 2> 593762 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 593763 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 593764 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 593764 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 594764 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 595765 DEBUG (ScheduledTrigger-2457-thread-2)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 596765 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 597765 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 598753 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD TRIGGERS
[junit4] 2> 598766 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 598780 INFO (qtp378414319-5484) [n:127.0.0.1:40041_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 598783 INFO (qtp1506398012-5393) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 598783 DEBUG (qtp1506398012-5395) [n:127.0.0.1:36711_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 598784 INFO (qtp1506398012-5395) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=28
[junit4] 2> 598784 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 598784 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 598784 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventMarkerAction}],
enabled=true}
[junit4] 2> 598785 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 598785 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 598786 INFO
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 598787 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 598787 DEBUG (ScheduledTrigger-2457-thread-3)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 598787 DEBUG (ScheduledTrigger-2457-thread-3)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 598789 INFO (qtp1506398012-5443) [n:127.0.0.1:36711_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 598792 INFO (qtp378414319-5482) [n:127.0.0.1:40041_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics
params={prefix=CONTAINER.fs.usableSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core}
status=0 QTime=0
[junit4] 2> 598792 DEBUG (qtp378414319-5485) [n:127.0.0.1:40041_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 598792 INFO (qtp378414319-5485) [n:127.0.0.1:40041_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 598793 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 598793 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 598793 INFO (qtp1506398012-5391) [n:127.0.0.1:36711_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 598793 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 598793 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerMR instantiated with properties: {event=nodeAdded, waitFor=1,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestEventMarkerAction}],
enabled=true}
[junit4] 2> 598793 DEBUG
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:36711_solr, 127.0.0.1:40041_solr]
[junit4] 2> 598793 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 598795 INFO
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 598795 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 2
[junit4] 2> 598795 DEBUG
(OverseerAutoScalingTriggerThread-99409892179771397-127.0.0.1:36711_solr-n_0000000001)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 598798 INFO (qtp1506398012-5391) [n:127.0.0.1:36711_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> 598798 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD NODE 1
[junit4] 2> 598799 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T07:27:37+10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@7c7085c2{/solr,null,AVAILABLE}
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.AbstractConnector Started ServerConnector@1386fdc3{SSL,[ssl,
http/1.1]}{127.0.0.1:43079}
[junit4] 2> 598800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.e.j.s.Server Started @600382ms
[junit4] 2> 598801 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=43079}
[junit4] 2> 598801 ERROR
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 598802 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr?
version 8.0.0
[junit4] 2> 598802 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 598802 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 598802 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-01-25T10:03:13.248Z
[junit4] 2> 598803 INFO (zkConnectionManagerCallback-1187-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 598803 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 598809 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35187/solr
[junit4] 2> 598810 INFO (zkConnectionManagerCallback-1191-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 598812 INFO
(zkConnectionManagerCallback-1193-thread-1-processing-n:127.0.0.1:43079_solr)
[n:127.0.0.1:43079_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 598815 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 598815 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 598816 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:43079_solr
[junit4] 2> 598817 INFO (zkCallback-1164-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 598817 INFO
(zkCallback-1182-thread-1-processing-n:127.0.0.1:40041_solr)
[n:127.0.0.1:40041_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 598817 INFO
(zkCallback-1152-thread-2-processing-n:127.0.0.1:36711_solr)
[n:127.0.0.1:36711_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 598817 INFO
(zkCallback-1192-thread-1-processing-n:127.0.0.1:43079_solr)
[n:127.0.0.1:43079_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 598863 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43079.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 598869 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43079.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 598869 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_43079.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@5130e844
[junit4] 2> 598870 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[403A938CC188709D])
[n:127.0.0.1:43079_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001/tempDir-001/node5/.
[junit4] 2> 599766 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 599789 DEBUG (ScheduledTrigger-2457-thread-2)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 599789 DEBUG (ScheduledTrigger-2457-thread-2)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 599789 DEBUG (ScheduledTrigger-2457-thread-2)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:43079_solr at time 168378563927595
[junit4] 2> 599796 DEBUG (ScheduledTrigger-2457-thread-1)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 3
[junit4] 2> 600767 DEBUG (ScheduledTrigger-2457-thread-3)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 600789 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 600790 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 600790 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerMR firing registered processor for nodes:
[127.0.0.1:43079_solr] added at times [168378563927595], now=168379564698738
[junit4] 2> 600790 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"9923b07d9e2bT55tr1r9dih9e70tcshahjf2yp",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":168378563927595,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[168378563927595],
[junit4] 2> "nodeNames":["127.0.0.1:43079_solr"]}}
[junit4] 2> 600790 DEBUG (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 600791 INFO (ScheduledTrigger-2457-thread-4)
[n:127.0.0.1:36711_solr ] o.a.s.c.a.SystemLogL
[...truncated too long message...]
MetricManager Closing metric reporters for
registry=solr.collection.collection1.shard1.leader, tag=1923344232
[junit4] 2> 794613 INFO (coreCloseExecutor-2659-thread-1)
[n:127.0.0.1:43287_solr c:collection1 s:shard1 r:core_node3
x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.collection1.shard1.leader, tag=332887883
[junit4] 2> 794616 INFO (coreCloseExecutor-2664-thread-1)
[n:127.0.0.1:35897_solr c:testMetricTrigger s:shard1 r:core_node6
x:testMetricTrigger_shard1_replica_n5] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testMetricTrigger.shard1.leader,
tag=1883107432
[junit4] 2> 794618 INFO (jetty-closer-1137-thread-8) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@7d773368{/solr,null,UNAVAILABLE}
[junit4] 2> 794618 INFO (jetty-closer-1137-thread-4) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@33015750{/solr,null,UNAVAILABLE}
[junit4] 2> 794618 INFO (jetty-closer-1137-thread-8) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 794619 INFO (jetty-closer-1137-thread-4) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 794621 INFO (jetty-closer-1137-thread-11) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@1c2aafca{/solr,null,UNAVAILABLE}
[junit4] 2> 794622 INFO (jetty-closer-1137-thread-11) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 794622 INFO (jetty-closer-1137-thread-3) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@ed747c7{/solr,null,UNAVAILABLE}
[junit4] 2> 794623 INFO (jetty-closer-1137-thread-3) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 794623 INFO (coreCloseExecutor-2663-thread-2)
[n:127.0.0.1:44845_solr c:testMetricTrigger s:shard2 r:core_node4
x:testMetricTrigger_shard2_replica_n3] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.core.testMetricTrigger.shard2.replica_n3,
tag=250027224
[junit4] 2> 794623 INFO (coreCloseExecutor-2663-thread-2)
[n:127.0.0.1:44845_solr c:testMetricTrigger s:shard2 r:core_node4
x:testMetricTrigger_shard2_replica_n3] o.a.s.m.r.SolrJmxReporter Closing
reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3e86b696: rootName
= solr_44845, domain = solr.core.testMetricTrigger.shard2.replica_n3, service
url = null, agent id = null] for registry
solr.core.testMetricTrigger.shard2.replica_n3 /
com.codahale.metrics.MetricRegistry@39c25b23
[junit4] 2> 794632 INFO (coreCloseExecutor-2663-thread-1)
[n:127.0.0.1:44845_solr c:collection1 s:shard1 r:core_node10
x:collection1_shard1_replica_n9] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.collection1.shard1.leader, tag=673565977
[junit4] 2> 794632 INFO (coreCloseExecutor-2663-thread-2)
[n:127.0.0.1:44845_solr c:testMetricTrigger s:shard2 r:core_node4
x:testMetricTrigger_shard2_replica_n3] o.a.s.m.SolrMetricManager Closing metric
reporters for registry=solr.collection.testMetricTrigger.shard2.leader,
tag=250027224
[junit4] 2> 794634 INFO (jetty-closer-1137-thread-1) [ ]
o.a.s.c.Overseer Overseer
(id=99409892179771415-127.0.0.1:44845_solr-n_0000000006) closing
[junit4] 2> 794634 INFO
(OverseerStateUpdate-99409892179771415-127.0.0.1:44845_solr-n_0000000006)
[n:127.0.0.1:44845_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:44845_solr
[junit4] 2> 794634 WARN
(OverseerAutoScalingTriggerThread-99409892179771415-127.0.0.1:44845_solr-n_0000000006)
[n:127.0.0.1:44845_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 794635 DEBUG (jetty-closer-1137-thread-1) [ ]
o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 794635 INFO (jetty-closer-1137-thread-1) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@3cfaa407{/solr,null,UNAVAILABLE}
[junit4] 2> 794636 INFO (jetty-closer-1137-thread-1) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 796047 INFO (jetty-closer-1137-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@751edc77{/solr,null,UNAVAILABLE}
[junit4] 2> 796048 INFO (jetty-closer-1137-thread-6) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 796048 ERROR
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-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> 796048 INFO
(SUITE-TriggerIntegrationTest-seed#[403A938CC188709D]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:35187 35187
[junit4] 2> 797065 INFO (Thread-1178) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:35187 35187
[junit4] 2> 797066 WARN (Thread-1178) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/aliases.json
[junit4] 2> 21 /solr/security.json
[junit4] 2> 10 /solr/configs/conf
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 118 /solr/collections/collection1/state.json
[junit4] 2> 33 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 22 /solr/clusterprops.json
[junit4] 2> 22 /solr/clusterstate.json
[junit4] 2> 6 /solr/autoscaling.json
[junit4] 2> 5
/solr/overseer_elect/election/99409892179771424-127.0.0.1:34775_solr-n_0000000009
[junit4] 2> 3
/solr/collections/collection1/leader_elect/shard1/election/99409892179771415-core_node10-n_0000000004
[junit4] 2> 3
/solr/collections/collection1/leader_elect/shard1/election/99409892179771421-core_node3-n_0000000001
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771451-127.0.0.1:35897_solr-n_0000000018
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771421-127.0.0.1:43287_solr-n_0000000008
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771445-127.0.0.1:46087_solr-n_0000000016
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771442-127.0.0.1:41255_solr-n_0000000015
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771415-127.0.0.1:44845_solr-n_0000000006
[junit4] 2> 2
/solr/overseer_elect/election/99409892179771397-127.0.0.1:36711_solr-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/collections
[junit4] 2> 21 /solr/live_nodes
[junit4] 2> 6 /solr/overseer/queue-work
[junit4] 2> 6 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 6 /solr/overseer/queue
[junit4] 2> 6 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/node_lost_triggerMR
[junit4] 2> 2 /solr/autoscaling/events/node_added_triggerCTOOR
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_403A938CC188709D-001
[junit4] 2> NOTE: test params are:
codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION,
chunkSize=31712, maxDocsPerChunk=2, blockSize=312),
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION,
chunkSize=31712, blockSize=312)),
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5d3cc985),
locale=fr-FR, timezone=Europe/Skopje
[junit4] 2> NOTE: Linux 4.13.0-31-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=8,threads=1,free=166719288,total=501743616
[junit4] 2> NOTE: All tests run in this JVM: [TestMacros,
TestSchemaResource, MetricsConfigTest, TestRandomRequestDistribution,
TestSubQueryTransformer, TestCustomSort, TestGroupingSearch,
TestCollapseQParserPlugin, TestExtendedDismaxParser,
ChaosMonkeySafeLeaderWithPullReplicasTest, TestDelegationWithHadoopAuth,
SolrSlf4jReporterTest, TestInPlaceUpdatesStandalone, ForceLeaderTest,
TestLuceneIndexBackCompat, TestPKIAuthenticationPlugin, TestMergePolicyConfig,
TestStressUserVersions, FieldAnalysisRequestHandlerTest,
TestManagedSchemaThreadSafety, CoreAdminCreateDiscoverTest,
WrapperMergePolicyFactoryTest, HdfsSyncSliceTest, DistribCursorPagingTest,
TestRetrieveFieldsOptimizer, RegexBytesRefFilterTest, TestQuerySenderNoQuery,
TestDynamicFieldResource, ExitableDirectoryReaderTest, DateRangeFieldTest,
BufferStoreTest, BaseCdcrDistributedZkTest, ImplicitSnitchTest,
TestSSLRandomization, TestPHPSerializedResponseWriter, TestFieldCacheSort,
TestAuthenticationFramework, TestSizeLimitedDistributedMap,
BigEndianAscendingWordSerializerTest, TestIBSimilarityFactory,
TestSimpleQParserPlugin, TestConfig, TestUnifiedSolrHighlighter,
TestPhraseSuggestions, SparseHLLTest, TestIndexingPerformance,
ExecutePlanActionTest, OpenCloseCoreStressTest, TestDistribStateManager,
TestApiFramework, SSLMigrationTest, ClassificationUpdateProcessorFactoryTest,
ConjunctionSolrSpellCheckerTest, SpellCheckCollatorTest, StatsComponentTest,
TestCollationField, TestEmbeddedSolrServerSchemaAPI, TestHalfAndHalfDocValues,
TestHighFrequencyDictionaryFactory, TestTrackingShardHandlerFactory,
TestMiniSolrCloudClusterSSL, IndexBasedSpellCheckerTest, ZkNodePropsTest,
CursorMarkTest, TestSchemalessBufferedUpdates, TestNumericTokenStream,
TestManagedResource, TestPullReplica, TestStressLucene, TestExactStatsCache,
DistributedQueryElevationComponentTest, CloneFieldUpdateProcessorFactoryTest,
SolrCLIZkUtilsTest, TestDefaultStatsCache, BasicAuthStandaloneTest,
DistributedExpandComponentTest, ConfigureRecoveryStrategyTest,
TriggerIntegrationTest]
[junit4] Completed [242/768 (1!)] on J0 in 216.16s, 14 tests, 1 failure <<<
FAILURES!
[...truncated 49877 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
