Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/4426/
Java: 64bit/jdk-9 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger
Error Message:
Stack Trace:
java.lang.AssertionError
at
__randomizedtesting.SeedInfo.seed([8708A23038F85A7:B27CBDAC5C6753E8]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.junit.Assert.assertNull(Assert.java:562)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testMetricTrigger(TriggerIntegrationTest.java:1575)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12730 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> Creating dataDir:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/init-core-data-001
[junit4] 2> 967080 WARN
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=7 numCloses=7
[junit4] 2> 967080 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 967082 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0,
clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 967082 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 967083 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001
[junit4] 2> 967083 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 967083 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 967084 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 967087 ERROR (Thread-2242) [ ] 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> 967184 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:63950
[junit4] 2> 967193 INFO (zkConnectionManagerCallback-2578-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967197 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 967197 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 967199 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 967200 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@69cc5ab0{/solr,null,AVAILABLE}
[junit4] 2> 967200 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@3abc49a0{/solr,null,AVAILABLE}
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1d30106d{HTTP/1.1,[http/1.1]}{127.0.0.1:63953}
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@4a9d6480{HTTP/1.1,[http/1.1]}{127.0.0.1:63952}
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ]
o.e.j.s.Server Started @969300ms
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ]
o.e.j.s.Server Started @969300ms
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=63953}
[junit4] 2> 967201 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=63952}
[junit4] 2> 967201 ERROR (jetty-launcher-2575-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 967201 ERROR (jetty-launcher-2575-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-07T19:01:03.308181Z
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 967202 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-07T19:01:03.308362Z
[junit4] 2> 967203 INFO (zkConnectionManagerCallback-2580-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967204 INFO (zkConnectionManagerCallback-2582-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967204 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 967204 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 967251 INFO (jetty-launcher-2575-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr
[junit4] 2> 967253 INFO (jetty-launcher-2575-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr
[junit4] 2> 967254 INFO (zkConnectionManagerCallback-2586-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967257 INFO (zkConnectionManagerCallback-2590-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967260 INFO
(zkConnectionManagerCallback-2592-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967262 INFO
(zkConnectionManagerCallback-2594-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967396 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 967397 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:63953_solr
[junit4] 2> 967398 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer
(id=72158773892808709-127.0.0.1:63953_solr-n_0000000000) starting
[junit4] 2> 967429 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 967432 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:63953_solr
[junit4] 2> 967433 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 967434 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 967434 INFO
(zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 967436 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: []
[junit4] 2> 967436 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 967436 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 967437 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:63952_solr
[junit4] 2> 967438 INFO
(zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 967438 INFO
(zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 967445 INFO
(zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 967446 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 967447 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 967447 DEBUG (ScheduledTrigger-3928-thread-1)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 967490 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63953.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967493 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63952.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967501 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63953.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967501 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63953.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967504 INFO (jetty-launcher-2575-thread-2)
[n:127.0.0.1:63953_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node2/.
[junit4] 2> 967508 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63952.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967508 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63952.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967509 INFO (jetty-launcher-2575-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node1/.
[junit4] 2> 967557 INFO (zkConnectionManagerCallback-2600-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967559 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid
0x1005c05c54f0007, likely client has closed socket
[junit4] 2> 967561 INFO (zkConnectionManagerCallback-2604-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967563 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 967565 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:63950/solr ready
[junit4] 2> 967579 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeMarkersRegistration
[junit4] 2> 967580 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 2
[junit4] 2> 967581 DEBUG
(zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 967581 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 967583 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 967583 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 967584 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 967587 INFO (qtp1606393036-9999) [n:127.0.0.1:63953_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 967594 INFO (qtp1606393036-9999) [n:127.0.0.1:63953_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 967595 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 967596 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 967596 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 967596 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 967596 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@6b8edc29{/solr,null,AVAILABLE}
[junit4] 2> 967597 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@67209eec{HTTP/1.1,[http/1.1]}{127.0.0.1:63965}
[junit4] 2> 967597 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.Server Started @969696ms
[junit4] 2> 967597 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=63965}
[junit4] 2> 967597 ERROR
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 967598 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™
version 8.0.0
[junit4] 2> 967598 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 967598 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 967598 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-07T19:01:03.704190Z
[junit4] 2> 967599 INFO (zkConnectionManagerCallback-2606-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967600 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 967613 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr
[junit4] 2> 967614 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid
0x1005c05c54f0009, likely client has closed socket
[junit4] 2> 967616 INFO (zkConnectionManagerCallback-2610-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967618 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ]
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid
0x1005c05c54f000a, likely client has closed socket
[junit4] 2> 967618 INFO
(zkConnectionManagerCallback-2612-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 967626 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 967632 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 967635 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:63965_solr
[junit4] 2> 967639 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 967640 INFO
(zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 967640 INFO
(zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 967641 INFO
(zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 967672 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63965.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967682 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63965.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967682 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63965.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 967684 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63965_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node3/.
[junit4] 2> 967717 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== KILL OVERSEER 1
[junit4] 2> 967718 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@1d30106d{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 967718 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=871893683
[junit4] 2> 967718 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 967719 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@4372d8de: rootName =
solr_63953, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@27129e6c
[junit4] 2> 967726 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 967726 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@7790e795: rootName =
solr_63953, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a
[junit4] 2> 967732 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 967732 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1f38e677: rootName =
solr_63953, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897
[junit4] 2> 967734 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:63953_solr
[junit4] 2> 967735 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 967735 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 967736 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.Overseer Overseer
(id=72158773892808709-127.0.0.1:63953_solr-n_0000000000) closing
[junit4] 2> 967736 INFO
(OverseerStateUpdate-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:63953_solr
[junit4] 2> 967737 WARN
(OverseerAutoScalingTriggerThread-72158773892808709-127.0.0.1:63953_solr-n_0000000000)
[n:127.0.0.1:63953_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 967737 DEBUG
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed
explicitly
[junit4] 2> 967738 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 967738 INFO
(zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 967738 INFO
(zkCallback-2593-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 967739 INFO
(zkCallback-2591-thread-1-processing-n:127.0.0.1:63953_solr)
[n:127.0.0.1:63953_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 967739 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@3abc49a0{/solr,null,UNAVAILABLE}
[junit4] 2> 967739 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 967740 INFO
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:63952_solr
[junit4] 2> 967742 INFO
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer
(id=72158773892808710-127.0.0.1:63952_solr-n_0000000001) starting
[junit4] 2> 967751 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 967752 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 967753 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 967753 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion -1
[junit4] 2> 967753 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 967755 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 967756 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 967756 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 968759 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 969780 DEBUG (ScheduledTrigger-3943-thread-2)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 970784 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 971785 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 972747 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD TRIGGERS
[junit4] 2> 972753 INFO (qtp264083190-10007) [n:127.0.0.1:63952_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> 972755 INFO (qtp1295431108-10061) [n:127.0.0.1:63965_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> 972756 DEBUG (qtp264083190-10003) [n:127.0.0.1:63952_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 972756 INFO (qtp264083190-10003) [n:127.0.0.1:63952_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 972757 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 972758 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 972758 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_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> 972758 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 972758 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 972759 INFO (qtp264083190-10007) [n:127.0.0.1:63952_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> 972759 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_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> 972760 DEBUG (qtp264083190-10005) [n:127.0.0.1:63952_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 972760 INFO (qtp264083190-10005) [n:127.0.0.1:63952_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 972761 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 972761 INFO (qtp264083190-10008) [n:127.0.0.1:63952_solr ]
o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 972761 INFO
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 972762 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 972762 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 972763 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_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> 972763 DEBUG
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63952_solr, 127.0.0.1:63965_solr]
[junit4] 2> 972764 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 4
[junit4] 2> 972764 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 972764 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 972764 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 972767 INFO
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 972768 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 972768 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 2
[junit4] 2> 972769 INFO (qtp264083190-10008) [n:127.0.0.1:63952_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 972769 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== ADD NODE 1
[junit4] 2> 972770 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 972771 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 972771 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 972771 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 972772 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@5705b223{/solr,null,AVAILABLE}
[junit4] 2> 972772 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@4df027ed{HTTP/1.1,[http/1.1]}{127.0.0.1:63981}
[junit4] 2> 972772 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.Server Started @974871ms
[junit4] 2> 972772 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=63981}
[junit4] 2> 972772 ERROR
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 972772 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™
version 8.0.0
[junit4] 2> 972773 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 972773 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 972773 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-07T19:01:08.879086Z
[junit4] 2> 972774 INFO (zkConnectionManagerCallback-2616-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 972775 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 972781 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr
[junit4] 2> 972783 INFO (zkConnectionManagerCallback-2620-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 972785 INFO
(zkConnectionManagerCallback-2622-thread-1-processing-n:127.0.0.1:63981_solr)
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 972786 DEBUG (ScheduledTrigger-3943-thread-2)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 972796 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 972800 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 972804 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:63981_solr
[junit4] 2> 972806 INFO
(zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 972806 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 972806 INFO
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 972807 INFO
(zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr)
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 972853 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63981.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 972862 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63981.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 972862 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63981.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 972863 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[n:127.0.0.1:63981_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node4/.
[junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 3
[junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 973777 DEBUG (ScheduledTrigger-3943-thread-3)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:63981_solr at time 1543888754788649
[junit4] 2> 973791 DEBUG (ScheduledTrigger-3943-thread-1)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 3
[junit4] 2> 974773 INFO
(OverseerCollectionConfigSetProcessor-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_triggerMR firing registered processor for nodes:
[127.0.0.1:63981_solr] added at times [1543888754788649], now=1543889757095677
[junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"57c289ccd4929T590altvb92ev1m9vvmhhnhcob",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":1543888754788649,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543888754788649],
[junit4] 2> "nodeNames":["127.0.0.1:63981_solr"]}}
[junit4] 2> 974779 DEBUG (ScheduledTrigger-3943-thread-2)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 3
[junit4] 2> 974780 DEBUG (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 974781 INFO (ScheduledTrigger-3943-thread-4)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 974781 DEBUG
(AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"57c289ccd4929T590altvb92ev1m9vvmhhnhcob",
[junit4] 2> "source":"node_added_triggerMR",
[junit4] 2> "eventTime":1543888754788649,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543888754788649],
[junit4] 2> "_enqueue_time_":1543889757742589,
[junit4] 2> "nodeNames":["127.0.0.1:63981_solr"]}}
[junit4] 2> 974783 DEBUG
(AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_triggerMR after 5000ms
[junit4] 2> 974783 DEBUG
(AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_triggerMR after 5000ms
[junit4] 2> 974783 DEBUG
(AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
.auto_add_replicas after 5000ms
[junit4] 2> 974783 DEBUG
(AutoscalingActionExecutor-3944-thread-1-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 2
ms for event id=57c289ccd4929T590altvb92ev1m9vvmhhnhcob
[junit4] 2> 977896 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.TriggerIntegrationTest ====== KILL OVERSEER 2
[junit4] 2> 977898 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@4a9d6480{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 977898 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1963702184
[junit4] 2> 977899 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 977899 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@4c184e: rootName =
solr_63952, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@5fe0e8b
[junit4] 2> 977912 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 977913 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1d9db155: rootName =
solr_63952, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a
[junit4] 2> 977920 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 977921 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@5fd22880: rootName =
solr_63952, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897
[junit4] 2> 977923 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:63952_solr
[junit4] 2> 977926 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 977927 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 977927 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.Overseer Overseer
(id=72158773892808710-127.0.0.1:63952_solr-n_0000000001) closing
[junit4] 2> 977928 INFO
(OverseerStateUpdate-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.Overseer Overseer Loop exiting :
127.0.0.1:63952_solr
[junit4] 2> 977929 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 977929 INFO
(zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr)
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 977929 INFO
(zkCallback-2593-thread-2-processing-n:127.0.0.1:63952_solr)
[n:127.0.0.1:63952_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 977929 INFO
(zkCallback-2611-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 977930 DEBUG
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed
explicitly
[junit4] 2> 977931 WARN
(OverseerAutoScalingTriggerThread-72158773892808710-127.0.0.1:63952_solr-n_0000000001)
[n:127.0.0.1:63952_solr ] o.a.s.c.a.OverseerTriggerThread
OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 977935 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@69cc5ab0{/solr,null,UNAVAILABLE}
[junit4] 2> 977935 INFO
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:63965_solr
[junit4] 2> 977935 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 977940 INFO
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.Overseer Overseer
(id=72158773892808715-127.0.0.1:63965_solr-n_0000000002) starting
[junit4] 2> 977977 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 977978 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 977979 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 977979 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_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> 977980 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 977980 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion -1
[junit4] 2> 977980 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 977981 INFO
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 977981 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from
marker path: 127.0.0.1:63952_solr
[junit4] 2> 977984 INFO
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest
TestEventMarkerAction init
[junit4] 2> 977985 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 2
[junit4] 2> 977985 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:63952_solr
[junit4] 2> 977986 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-2)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-2)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-3)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 977988 DEBUG (ScheduledTrigger-3954-thread-3)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:63952_solr
[junit4] 2> 978997 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_triggerMR with currently live nodes: 2
[junit4] 2> 978997 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:63952_solr]
[junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_triggerMR
[junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"57c29979df94dT590altvb92ev1m9vvmhhnhcod",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":1543892962769229,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543892962769229],
[junit4] 2> "nodeNames":["127.0.0.1:63952_solr"]}}
[junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-2)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 2
[junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 978998 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_triggerMR, node_added_triggerMR, .auto_add_replicas]
[junit4] 2> 978999 INFO (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 979000 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"57c29979df94dT590altvb92ev1m9vvmhhnhcod",
[junit4] 2> "source":"node_lost_triggerMR",
[junit4] 2> "eventTime":1543892962769229,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543892962769229],
[junit4] 2> "_enqueue_time_":1543893976120858,
[junit4] 2> "nodeNames":["127.0.0.1:63952_solr"]}}
[junit4] 2> 979000 INFO
(TEST-TriggerIntegrationTest.testNodeMarkersRegistration-seed#[8708A23038F85A7])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeMarkersRegistration
[junit4] 2> 979005 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_triggerMR after 5000ms
[junit4] 2> 979005 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_triggerMR after 5000ms
[junit4] 2> 979005 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
.auto_add_replicas after 5000ms
[junit4] 2> 979005 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 5
ms for event id=57c29979df94dT590altvb92ev1m9vvmhhnhcod
[junit4] 2> 979015 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 979015 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 6
[junit4] 2> 979016 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 979016 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 979021 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 979021 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 979022 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 979026 INFO (qtp1230244092-10098) [n:127.0.0.1:63981_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=1
[junit4] 2> 979028 INFO (qtp1295431108-10066) [n:127.0.0.1:63965_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> 979028 DEBUG (qtp1295431108-10063) [n:127.0.0.1:63965_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 979029 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 979029 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 979030 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 979030 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 979031 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 979033 INFO
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 979034 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 979034 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 979034 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 979035 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 979035 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 979035 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 979035 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 979035 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 979036 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@4f54fc87{/solr,null,AVAILABLE}
[junit4] 2> 979036 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@585a3f39{HTTP/1.1,[http/1.1]}{127.0.0.1:63995}
[junit4] 2> 979036 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.e.j.s.Server Started @981135ms
[junit4] 2> 979036 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=63995}
[junit4] 2> 979036 ERROR
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 979037 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
8.0.0
[junit4] 2> 979037 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 979037 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 979037 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-07T19:01:15.143548Z
[junit4] 2> 979039 INFO (zkConnectionManagerCallback-2626-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979039 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 979045 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:63950/solr
[junit4] 2> 979047 INFO (zkConnectionManagerCallback-2630-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979050 INFO
(zkConnectionManagerCallback-2632-thread-1-processing-n:127.0.0.1:63995_solr)
[n:127.0.0.1:63995_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 979059 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 979063 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 979066 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:63995_solr
[junit4] 2> 979068 INFO
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 979069 INFO
(zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr)
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 979069 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 979069 INFO
(zkCallback-2631-thread-1-processing-n:127.0.0.1:63995_solr)
[n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 979110 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63995.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 979119 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63995.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 979119 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_63995.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@3882036c
[junit4] 2> 979121 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7])
[n:127.0.0.1:63995_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001/tempDir-001/node5/.
[junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 980042 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:63995_solr at time 1543895020252947
[junit4] 2> 981053 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 981054 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:63995_solr] added at times [1543895020252947], now=1543897034718748
[junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"57c2a1240af13T590altvb92ev1m9vvmhhnhcof",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1543895020252947,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543895020252947],
[junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}}
[junit4] 2> 982057 DEBUG (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 982058 INFO (ScheduledTrigger-3954-thread-4)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 982058 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"57c2a1240af13T590altvb92ev1m9vvmhhnhcof",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1543895020252947,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543895020252947],
[junit4] 2> "_enqueue_time_":1543897035012807,
[junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}}
[junit4] 2> 982063 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 982063 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 4
ms for event id=57c2a1240af13T590altvb92ev1m9vvmhhnhcof
[junit4] 2> 982064 INFO (qtp1295431108-10063) [n:127.0.0.1:63965_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> 982066 INFO (qtp1230244092-10102) [n:127.0.0.1:63981_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> 982067 INFO (qtp296880580-10138) [n:127.0.0.1:63995_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> 982067 DEBUG (qtp296880580-10134) [n:127.0.0.1:63995_solr ]
o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 982068 INFO (qtp296880580-10134) [n:127.0.0.1:63995_solr ]
o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 982068 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 982069 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:63995_solr, 127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 982069 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=2,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 982069 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 982070 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 982070 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 984069 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[8708A23038F85A7]) [
] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 984090 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 984091 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 9
[junit4] 2> 984092 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 984092 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 984094 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 984094 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 984095 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 984097 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 984105 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 984108 INFO (qtp1295431108-10065) [n:127.0.0.1:63965_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> 984109 INFO (qtp1230244092-10103) [n:127.0.0.1:63981_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> 984110 INFO (qtp296880580-10140) [n:127.0.0.1:63995_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> 984111 DEBUG (qtp1230244092-10102) [n:127.0.0.1:63981_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 984115 INFO (qtp1230244092-10102) [n:127.0.0.1:63981_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 984116 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 984116 DEBUG
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:63995_solr, 127.0.0.1:63981_solr, 127.0.0.1:63965_solr]
[junit4] 2> 984116 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 984118 INFO
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 984118 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 984121 DEBUG
(OverseerAutoScalingTriggerThread-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 984122 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.e.j.s.AbstractConnector Stopped
ServerConnector@585a3f39{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 984122 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1051152417
[junit4] 2> 984122 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 3
[junit4] 2> 984122 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 984122 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1b6347f6: rootName =
solr_63995, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@3cfb960e
[junit4] 2> 984133 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 984133 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1c48ba13: rootName =
solr_63995, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@2a3cc19a
[junit4] 2> 984140 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 984140 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@2485358e: rootName =
solr_63995, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@323a4897
[junit4] 2> 984143 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:63995_solr
[junit4] 2> 984144 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 984144 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647
transient cores
[junit4] 2> 984145 INFO
(zkCallback-2621-thread-1-processing-n:127.0.0.1:63981_solr)
[n:127.0.0.1:63981_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 984145 INFO (zkCallback-2603-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 984145 INFO
(zkCallback-2611-thread-2-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 984145 INFO
(zkCallback-2631-thread-1-processing-n:127.0.0.1:63995_solr)
[n:127.0.0.1:63995_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 984147 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@4f54fc87{/solr,null,UNAVAILABLE}
[junit4] 2> 984147 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[8708A23038F85A7]) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 985149 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 2
[junit4] 2> 985149 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:63995_solr
[junit4] 2> 986108 INFO
(OverseerCollectionConfigSetProcessor-72158773892808715-127.0.0.1:63965_solr-n_0000000002)
[n:127.0.0.1:63965_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000004 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 2
[junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:63995_solr]
[junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"57c2b429c8df4T590altvb92ev1m9vvmhhnhcoh",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":1543900126547444,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1543900126547444],
[junit4] 2> "nodeNames":["127.0.0.1:63995_solr"]}}
[junit4] 2> 986150 DEBUG (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger]
[junit4] 2> 986151 INFO (ScheduledTrigger-3954-thread-1)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 986151 DEBUG
(AutoscalingActionExecutor-3955-thread-1-processing-n:127.0.0.1:63965_solr)
[n:127.0.0.1:63965_solr ] o.a.s.c.a.ScheduledTriggers -- processing
[...truncated too long message...]
PoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1159727 WARN
(zkCallback-2796-thread-1-processing-n:127.0.0.1:64537_solr)
[n:127.0.0.1:64537_solr ] o.a.s.c.ZkController Unable to register nodeLost
path for 127.0.0.1:64537_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:64537_solr
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:130)
[junit4] 2> at
org.apache.zookeeper.KeeperException.create(KeeperException.java:54)
[junit4] 2> at
org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:786)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.lambda$create$7(SolrZkClient.java:365)
[junit4] 2> at
org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:365)
[junit4] 2> at
org.apache.solr.cloud.ZkController.lambda$registerLiveNodesListener$2(ZkController.java:882)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.lambda$refreshLiveNodes$1(ZkStateReader.java:704)
[junit4] 2> at
java.base/java.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4724)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269)
[junit4] 2> at
java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514)
[junit4] 2> at
java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
[junit4] 2> at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
[junit4] 2> at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1159726 WARN
(zkCallback-2766-thread-2-processing-n:127.0.0.1:64426_solr)
[n:127.0.0.1:64426_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1159726 INFO (jetty-closer-2576-thread-12) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1159728 INFO (jetty-closer-2576-thread-11) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@7d90353b{/solr,null,UNAVAILABLE}
[junit4] 2> 1159728 INFO (jetty-closer-2576-thread-11) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1159742 WARN
(zkCallback-2796-thread-3-processing-n:127.0.0.1:64537_solr)
[n:127.0.0.1:64537_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1159743 INFO (jetty-closer-2576-thread-13) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@7e49731d{/solr,null,UNAVAILABLE}
[junit4] 2> 1159743 INFO (jetty-closer-2576-thread-13) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1160007 INFO (jetty-closer-2576-thread-6) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@5803a918{/solr,null,UNAVAILABLE}
[junit4] 2> 1160007 INFO (jetty-closer-2576-thread-6) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 1160009 ERROR
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-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> 1160009 INFO
(SUITE-TriggerIntegrationTest-seed#[8708A23038F85A7]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:63950 63950
[junit4] 2> 1160024 INFO (Thread-2242) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:63950 63950
[junit4] 2> 1160169 WARN (Thread-2242) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/clusterprops.json
[junit4] 2> 22 /solr/aliases.json
[junit4] 2> 21 /solr/security.json
[junit4] 2> 21 /solr/collections/collection1/terms/shard1
[junit4] 2> 6 /solr/configs/conf
[junit4] 2> 2 /solr/collections/testMetricTrigger/terms/shard1
[junit4] 2> 2 /solr/collections/testMetricTrigger/terms/shard2
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 64 /solr/collections/collection1/state.json
[junit4] 2> 22 /solr/clusterstate.json
[junit4] 2> 11 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 6 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/72158773892808742-127.0.0.1:64180_solr-n_0000000011
[junit4] 2> 3
/solr/overseer_elect/election/72158773892808752-127.0.0.1:64302_solr-n_0000000014
[junit4] 2> 2
/solr/collections/collection1/leader_elect/shard1/election/72158773892808736-core_node4-n_0000000000
[junit4] 2> 2
/solr/overseer_elect/election/72158773892808730-127.0.0.1:64129_solr-n_0000000007
[junit4] 2> 2
/solr/overseer_elect/election/72158773892808736-127.0.0.1:64172_solr-n_0000000009
[junit4] 2> 2
/solr/overseer_elect/election/72158773892808761-127.0.0.1:64426_solr-n_0000000017
[junit4] 2> 2
/solr/overseer_elect/election/72158773892808718-127.0.0.1:63981_solr-n_0000000003
[junit4] 2> 2
/solr/collections/collection1/leader_elect/shard1/election/72158773892808739-core_node3-n_0000000001
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/live_nodes
[junit4] 2> 22 /solr/collections
[junit4] 2> 6 /solr/overseer/queue-work
[junit4] 2> 6 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 6 /solr/overseer/queue
[junit4] 2> 6 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/node_lost_triggerMR
[junit4] 2> 2 /solr/autoscaling/events/node_added_triggerCTOOR
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at:
/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_8708A23038F85A7-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70),
sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@699ee3c2),
locale=en-AT, timezone=SystemV/EST5
[junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9
(64-bit)/cpus=3,threads=1,free=153156352,total=360710144
[junit4] 2> NOTE: All tests run in this JVM: [TestRestoreCore,
TestBulkSchemaAPI, NodeLostTriggerTest, ClusterStateUpdateTest,
AsyncCallRequestStatusResponseTest, EchoParamsTest, TestDocumentBuilder,
SolrXmlInZkTest, SystemLogListenerTest, TlogReplayBufferedWhileIndexingTest,
DeleteReplicaTest, CleanupOldIndexTest, TestSolrDeletionPolicy2,
BasicAuthIntegrationTest, TestDistributedGrouping, HdfsRecoveryZkTest,
ReplicationFactorTest, TestCollapseQParserPlugin, TestSolrQueryParser,
ParsingFieldUpdateProcessorsTest, TestStressInPlaceUpdates,
TestManagedStopFilterFactory, TestCollectionsAPIViaSolrCloudCluster,
DirectUpdateHandlerTest, SolrShardReporterTest, ScriptEngineTest,
BufferStoreTest, FileBasedSpellCheckerTest, PropertiesRequestHandlerTest,
HdfsAutoAddReplicasIntegrationTest, OverseerRolesTest, TestIndexingPerformance,
SparseHLLTest, TestCoreBackup, RegexBoostProcessorTest,
SpatialRPTFieldTypeTest, ComputePlanActionTest, TestGraphTermsQParserPlugin,
BasicDistributedZk2Test, TestDynamicLoading, CdcrVersionReplicationTest,
TestSolr4Spatial2, ZkSolrClientTest, TestFreeTextSuggestions,
DistributedIntervalFacetingTest, TestSimDistributedQueue,
TestSolrCoreProperties, UUIDFieldTest, ZkShardTermsTest,
TestSolrCloudWithDelegationTokens, DistanceUnitsTest,
TestClassicSimilarityFactory, TestSolr4Spatial, SoftAutoCommitTest,
TestConfigSetProperties, TestRandomRequestDistribution, BadIndexSchemaTest,
BasicFunctionalityTest, TestDocBasedVersionConstraints, TestSchemaNameResource,
SolrSlf4jReporterTest, TestExactStatsCache, TolerantUpdateProcessorTest,
ReplaceNodeNoTargetTest, TestScoreJoinQPScore, IndexSchemaTest,
TestFastLRUCache, HdfsCollectionsAPIDistributedZkTest,
TestSubQueryTransformerDistrib, BooleanFieldTest, NotRequiredUniqueKeyTest,
CloudMLTQParserTest, TestDynamicFieldCollectionResource,
DistributedQueryComponentOptimizationTest, BaseCdcrDistributedZkTest,
TestOrdValues, JSONWriterTest, TestSchemaManager, SolrGangliaReporterTest,
TestExtendedDismaxParser, TestRawTransformer, DebugComponentTest,
TestStressReorder, MetricTriggerTest, ClassificationUpdateProcessorFactoryTest,
TestWriterPerf, TestInfoStreamLogging, URLClassifyProcessorTest,
RecoveryAfterSoftCommitTest, TestRequestForwarding, HdfsNNFailoverTest,
HealthCheckHandlerTest, TestExportWriter, TestManagedSynonymGraphFilterFactory,
TestSolrConfigHandlerConcurrent, SuggesterTest, TestSimpleTrackingShardHandler,
TestSolrCloudWithSecureImpersonation, SegmentsInfoRequestHandlerTest,
TestDistributedMissingSort, TestNumericTerms64, SyncSliceTest,
TestNumericTokenStream, TestConfigSetsAPIZkFailure, CreateRoutedAliasTest,
TriggerIntegrationTest]
[junit4] Completed [227/775 (1!)] on J1 in 193.10s, 14 tests, 1 failure <<<
FAILURES!
[...truncated 42714 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org
