Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/363/
1 tests failed.
FAILED:
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeAddedTriggerRestoreState
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at
__randomizedtesting.SeedInfo.seed([5FDAC3FCD3733791:D7E74A83E9B3D63C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at
org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testNodeAddedTriggerRestoreState(TriggerIntegrationTest.java:426)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 14024 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 1989490 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks:
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/init-core-data-001
[junit4] 2> 1989490 WARN
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=24 numCloses=24
[junit4] 2> 1989490 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true)
w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1989492 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via:
@org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1989492 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001
[junit4] 2> 1989492 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1989493 INFO (Thread-6158) [ ] o.a.s.c.ZkTestServer client
port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1989493 INFO (Thread-6158) [ ] o.a.s.c.ZkTestServer
Starting server
[junit4] 2> 1989496 ERROR (Thread-6158) [ ] 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> 1989593 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.ZkTestServer start zk server on port:54329
[junit4] 2> 1989596 INFO (zkConnectionManagerCallback-7225-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989601 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
0x1044f4ebca60000, likely client has closed socket
[junit4] 2> 1989603 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1989603 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1989605 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1989605 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1989605 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1989605 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1989606 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1989606 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1989606 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@4d8b2b6e{/solr,null,AVAILABLE}
[junit4] 2> 1989606 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@666936c8{/solr,null,AVAILABLE}
[junit4] 2> 1989607 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@1511aed{HTTP/1.1,[http/1.1]}{127.0.0.1:34705}
[junit4] 2> 1989607 INFO (jetty-launcher-7222-thread-1) [ ]
o.e.j.s.Server Started @1991438ms
[junit4] 2> 1989607 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=34705}
[junit4] 2> 1989608 ERROR (jetty-launcher-7222-thread-1) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1989608 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@36e061ee{HTTP/1.1,[http/1.1]}{127.0.0.1:44300}
[junit4] 2> 1989608 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1989609 INFO (jetty-launcher-7222-thread-2) [ ]
o.e.j.s.Server Started @1991439ms
[junit4] 2> 1989609 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1989609 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=44300}
[junit4] 2> 1989609 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1989609 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:38.802Z
[junit4] 2> 1989609 ERROR (jetty-launcher-7222-thread-2) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1989610 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1989610 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1989610 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1989610 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:38.803Z
[junit4] 2> 1989611 INFO (zkConnectionManagerCallback-7227-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989612 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1989612 INFO (zkConnectionManagerCallback-7229-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989613 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1989623 INFO (jetty-launcher-7222-thread-2) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 1989624 INFO (jetty-launcher-7222-thread-1) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 1989624 INFO (zkConnectionManagerCallback-7233-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989625 INFO (zkConnectionManagerCallback-7237-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989628 INFO
(zkConnectionManagerCallback-7239-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989628 INFO
(zkConnectionManagerCallback-7241-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989711 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1989711 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.OverseerElectionContext I am going to be
the leader 127.0.0.1:34705_solr
[junit4] 2> 1989712 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.Overseer Overseer
(id=73270693535809542-127.0.0.1:34705_solr-n_0000000000) starting
[junit4] 2> 1989718 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:34705_solr
[junit4] 2> 1989719 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Adding
.autoAddReplicas trigger
[junit4] 2> 1989724 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 1
[junit4] 2> 1989724 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1989725 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:34705_solr]
[junit4] 2> 1989725 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1989725 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 1
[junit4] 2> 1989726 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1989727 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1989727 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
.auto_add_replicas with currently live nodes: 1
[junit4] 2> 1989730 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (1)
[junit4] 2> 1989733 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1989734 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:44300_solr
[junit4] 2> 1989735 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1989735 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (1) -> (2)
[junit4] 2> 1989820 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34705.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989845 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34705.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989845 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_34705.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989846 INFO (jetty-launcher-7222-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node1/.
[junit4] 2> 1989848 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44300.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989855 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44300.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989855 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_44300.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1989856 INFO (jetty-launcher-7222-thread-2)
[n:127.0.0.1:44300_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node2/.
[junit4] 2> 1989884 INFO (zkConnectionManagerCallback-7247-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989887 INFO (zkConnectionManagerCallback-7251-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989888 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1989888 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:54329/solr ready
[junit4] 2> 1989915 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.SolrTestCaseJ4 ###Starting testNodeAddedTrigger
[junit4] 2> 1989915 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 1989916 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 2
[junit4] 2> 1989916 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 2
[junit4] 2> 1989917 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1989917 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1989918 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1989924 INFO (qtp870656928-27141) [n:127.0.0.1:34705_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> 1989925 INFO (qtp386038279-27138) [n:127.0.0.1:44300_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> 1989925 DEBUG (qtp870656928-27134) [n:127.0.0.1:34705_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1989927 INFO (qtp870656928-27134) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 1989927 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 3
[junit4] 2> 1989932 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:34705_solr]
[junit4] 2> 1989932 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=3,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1989932 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 3
[junit4] 2> 1989933 INFO
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1989934 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1989934 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1989934 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1989934 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1989934 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1989935 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1989935 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1989936 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1989936 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@623fd472{/solr,null,AVAILABLE}
[junit4] 2> 1989937 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.AbstractConnector Started
ServerConnector@ec602c{HTTP/1.1,[http/1.1]}{127.0.0.1:39852}
[junit4] 2> 1989937 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.Server Started @1991768ms
[junit4] 2> 1989937 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=39852}
[junit4] 2> 1989937 ERROR
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 1989937 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 1989937 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port
null
[junit4] 2> 1989938 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1989938 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:39.131Z
[junit4] 2> 1989939 INFO (zkConnectionManagerCallback-7253-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989940 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1989949 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 1989950 INFO (zkConnectionManagerCallback-7257-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989952 INFO
(zkConnectionManagerCallback-7259-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1989956 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 1989958 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1989960 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:39852_solr
[junit4] 2> 1989961 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1989961 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1989961 INFO
(zkCallback-7258-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 1989961 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1990028 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39852.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1990038 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39852.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1990038 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_39852.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1990040 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:39852_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node3/.
[junit4] 2> 1990936 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1990936 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1990936 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node:
127.0.0.1:39852_solr at time 18510430792227744
[junit4] 2> 1991937 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1991937 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1992937 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1992937 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1993938 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Running
NodeAddedTrigger node_added_trigger
[junit4] 2> 1993938 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 3
[junit4] 2> 1993938 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger firing registered processor for nodes:
[127.0.0.1:39852_solr] added at times [18510430792227744], now=18510433794295675
[junit4] 2> 1993938 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"41c32384029ba0T3x1soud8hai70iqvybkylqxs1",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":18510430792227744,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510430792227744],
[junit4] 2> "nodeNames":["127.0.0.1:39852_solr"]}}
[junit4] 2> 1993939 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_added_trigger]
[junit4] 2> 1993940 INFO (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1993940 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"41c32384029ba0T3x1soud8hai70iqvybkylqxs1",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":18510430792227744,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510430792227744],
[junit4] 2> "_enqueue_time_":18510433795331082,
[junit4] 2> "nodeNames":["127.0.0.1:39852_solr"]}}
[junit4] 2> 1993941 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_added_trigger after 5000ms
[junit4] 2> 1993941 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=41c32384029ba0T3x1soud8hai70iqvybkylqxs1
[junit4] 2> 1993945 INFO (qtp870656928-27143) [n:127.0.0.1:34705_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> 1993947 INFO (qtp1582300571-27197) [n:127.0.0.1:39852_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> 1993949 INFO (qtp386038279-27142) [n:127.0.0.1:44300_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> 1993949 DEBUG (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1993949 INFO (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=7
[junit4] 2> 1993950 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 4
[junit4] 2> 1993950 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:39852_solr, 127.0.0.1:34705_solr]
[junit4] 2> 1993950 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger
node_added_trigger instantiated with properties: {event=nodeAdded, waitFor=3,
actions=[{name=test,
class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}],
enabled=true}
[junit4] 2> 1993950 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 4
[junit4] 2> 1993951 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1993951 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1995950 INFO
(TEST-TriggerIntegrationTest.testNodeAddedTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 1995988 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTriggerRestoreState
[junit4] 2> 1995989 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode
version 5
[junit4] 2> 1995989 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 5
[junit4] 2> 1995989 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 5
[junit4] 2> 1995991 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1995991 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1995991 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1995992 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1995993 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1995993 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1995993 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1995994 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@db7676d{/solr,null,AVAILABLE}
[junit4] 2> 1995994 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.AbstractConnector Started
ServerConnector@7bf866e9{HTTP/1.1,[http/1.1]}{127.0.0.1:37275}
[junit4] 2> 1995994 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.Server Started @1997825ms
[junit4] 2> 1995994 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=37275}
[junit4] 2> 1995995 ERROR
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging
may be missing or incomplete.
[junit4] 2> 1995995 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™
version 7.3.0
[junit4] 2> 1995995 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on
port null
[junit4] 2> 1995995 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1995995 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:45.188Z
[junit4] 2> 1995997 INFO (zkConnectionManagerCallback-7263-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1995997 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1996006 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 1996008 INFO (zkConnectionManagerCallback-7267-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1996010 INFO
(zkConnectionManagerCallback-7269-thread-1-processing-n:127.0.0.1:37275_solr)
[n:127.0.0.1:37275_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1996018 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 1996020 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1996023 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:37275_solr
[junit4] 2> 1996024 INFO
(zkCallback-7258-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1996024 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1996024 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1996024 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1996028 INFO
(zkCallback-7268-thread-1-processing-n:127.0.0.1:37275_solr)
[n:127.0.0.1:37275_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 1996113 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37275.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1996123 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37275.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1996123 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_37275.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 1996124 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:37275_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node4/.
[junit4] 2> 1996189 INFO (qtp870656928-27137) [n:127.0.0.1:34705_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> 1996190 INFO (qtp1637758569-27225) [n:127.0.0.1:37275_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> 1996192 INFO (qtp1582300571-27202) [n:127.0.0.1:39852_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> 1996193 INFO (qtp386038279-27147) [n:127.0.0.1:44300_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> 1996193 DEBUG (qtp386038279-27148) [n:127.0.0.1:44300_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1996193 INFO (qtp386038279-27148) [n:127.0.0.1:44300_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/cluster/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1996193 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 6
[junit4] 2> 1996194 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:39852_solr, 127.0.0.1:37275_solr,
127.0.0.1:34705_solr]
[junit4] 2> 1996194 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.AbstractConnector Stopped
ServerConnector@7bf866e9{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1996194 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 6
[junit4] 2> 1996194 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1698833564
[junit4] 2> 1996195 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.node, tag=null
[junit4] 2> 1996195 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@3522c719: rootName =
solr_37275, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@763eb224
[junit4] 2> 1996195 INFO
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1996196 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1996196 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1996196 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 4
[junit4] 2> 1996201 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jvm, tag=null
[junit4] 2> 1996202 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1255f1a0: rootName =
solr_37275, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@3f48e6fe
[junit4] 2> 1996207 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.jetty, tag=null
[junit4] 2> 1996207 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@22408406: rootName =
solr_37275, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@4df87cdb
[junit4] 2> 1996208 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:37275_solr
[junit4] 2> 1996208 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.cluster, tag=null
[junit4] 2> 1996208 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1996209 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 1996209 INFO
(zkCallback-7268-thread-1-processing-n:127.0.0.1:37275_solr)
[n:127.0.0.1:37275_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1996208 INFO
(zkCallback-7258-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1996208 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (4) -> (3)
[junit4] 2> 1996209 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1997197 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 1997197 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:37275_solr
[junit4] 2> 1997710 WARN
(zkCallback-7268-thread-1-processing-n:127.0.0.1:37275_solr)
[n:127.0.0.1:37275_solr ] o.a.s.c.ZkController Unable to register nodeLost
path for 127.0.0.1:37275_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:37275_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.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 1997711 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@db7676d{/solr,null,UNAVAILABLE}
[junit4] 2> 1997711 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1998198 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 1999198 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 1999216 INFO (qtp870656928-27145) [n:127.0.0.1:34705_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> 1999218 INFO (qtp1582300571-27200) [n:127.0.0.1:39852_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> 1999219 INFO (qtp386038279-27138) [n:127.0.0.1:44300_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> 1999220 DEBUG (qtp870656928-27141) [n:127.0.0.1:34705_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1999220 INFO (qtp870656928-27141) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1999220 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 7
[junit4] 2> 1999220 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:39852_solr, 127.0.0.1:34705_solr]
[junit4] 2> 1999221 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 7
[junit4] 2> 1999221 INFO
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1999222 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from
marker path: 127.0.0.1:37275_solr
[junit4] 2> 1999222 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1999222 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_restore_trigger with currently live nodes: 3
[junit4] 2> 1999222 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:37275_solr]
[junit4] 2> 1999222 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 7, lastZnodeVersion 7
[junit4] 2> 1999222 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"41c32571e3d6f7T3x1soud8hai70iqvybkylqxs3",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":18510439078156023,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510439078156023],
[junit4] 2> "nodeNames":["127.0.0.1:37275_solr"]}}
[junit4] 2> 1999222 DEBUG (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_restore_trigger]
[junit4] 2> 1999223 INFO (ScheduledTrigger-8845-thread-2)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 1999223 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"41c32571e3d6f7T3x1soud8hai70iqvybkylqxs3",
[junit4] 2> "source":"node_lost_restore_trigger",
[junit4] 2> "eventTime":18510439078156023,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510439078156023],
[junit4] 2> "_enqueue_time_":18510439078959634,
[junit4] 2> "nodeNames":["127.0.0.1:37275_solr"]}}
[junit4] 2> 1999223 INFO
(TEST-TriggerIntegrationTest.testNodeLostTriggerRestoreState-seed#[5FDAC3FCD3733791])
[ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTriggerRestoreState
[junit4] 2> 1999224 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_restore_trigger after 5000ms
[junit4] 2> 1999224 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 0
ms for event id=41c32571e3d6f7T3x1soud8hai70iqvybkylqxs3
[junit4] 2> 1999243 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 1999243 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 8
[junit4] 2> 1999243 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 8
[junit4] 2> 1999243 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 8
[junit4] 2> 1999245 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 1999245 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1999245 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 8, lastZnodeVersion 8
[junit4] 2> 1999245 INFO (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with
params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1999249 INFO (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections
params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 1999250 INFO (qtp870656928-27143) [n:127.0.0.1:34705_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> 1999250 INFO (qtp1582300571-27202) [n:127.0.0.1:39852_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> 1999251 INFO (qtp386038279-27148) [n:127.0.0.1:44300_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> 1999251 DEBUG (qtp870656928-27141) [n:127.0.0.1:34705_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1999251 INFO (qtp870656928-27141) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 1999251 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 9
[junit4] 2> 1999252 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:39852_solr, 127.0.0.1:34705_solr]
[junit4] 2> 1999252 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 9
[junit4] 2> 1999253 INFO
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.TriggerIntegrationTest
TestTriggerAction init
[junit4] 2> 1999253 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 1999253 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 9, lastZnodeVersion 9
[junit4] 2> 1999253 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.AbstractConnector Stopped
ServerConnector@ec602c{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1999253 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.CoreContainer Shutting down CoreContainer instance=614049576
[junit4] 2> 1999254 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 3
[junit4] 2> 1999254 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node,
tag=null
[junit4] 2> 1999254 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@1eb72d3: rootName =
solr_39852, domain = solr.node, service url = null, agent id = null] for
registry solr.node / com.codahale.metrics.MetricRegistry@62241afd
[junit4] 2> 1999260 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm,
tag=null
[junit4] 2> 1999260 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@fc9f559: rootName =
solr_39852, domain = solr.jvm, service url = null, agent id = null] for
registry solr.jvm / com.codahale.metrics.MetricRegistry@3f48e6fe
[junit4] 2> 1999264 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty,
tag=null
[junit4] 2> 1999264 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.r.SolrJmxReporter Closing reporter
[org.apache.solr.metrics.reporters.SolrJmxReporter@237c3dca: rootName =
solr_39852, domain = solr.jetty, service url = null, agent id = null] for
registry solr.jetty / com.codahale.metrics.MetricRegistry@4df87cdb
[junit4] 2> 1999265 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.ZkController Remove node as live in
ZooKeeper:/live_nodes/127.0.0.1:39852_solr
[junit4] 2> 1999266 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster,
tag=null
[junit4] 2> 1999266 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1999266 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for
2147483647 transient cores
[junit4] 2> 1999266 INFO
(zkCallback-7258-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 1999266 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 1999267 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (2)
[junit4] 2> 2000254 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 2
[junit4] 2> 2000254 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Tracking lost node:
127.0.0.1:39852_solr
[junit4] 2> 2000767 WARN
(zkCallback-7258-thread-1-processing-n:127.0.0.1:39852_solr)
[n:127.0.0.1:39852_solr ] o.a.s.c.ZkController Unable to register nodeLost
path for 127.0.0.1:39852_solr
[junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException:
KeeperErrorCode = Session expired for /autoscaling/nodeLost/127.0.0.1:39852_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.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2000768 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@623fd472{/solr,null,UNAVAILABLE}
[junit4] 2> 2000768 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.e.j.s.session Stopped scavenging
[junit4] 2> 2001248 INFO
(OverseerCollectionConfigSetProcessor-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.OverseerTaskQueue Response ZK path:
/overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may
have disconnected from ZooKeeper
[junit4] 2> 2001255 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 2
[junit4] 2> 2002256 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger:
node_lost_trigger with currently live nodes: 2
[junit4] 2> 2002256 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing
registered processor for lost nodes: [127.0.0.1:39852_solr]
[junit4] 2> 2002256 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown
inactive - processing event: {
[junit4] 2> "id":"41c325af7201beT3x1soud8hai70iqvybkylqxs5",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":18510440110883262,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510440110883262],
[junit4] 2> "nodeNames":["127.0.0.1:39852_solr"]}}
[junit4] 2> 2002256 DEBUG (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers:
[node_lost_trigger]
[junit4] 2> 2002256 INFO (ScheduledTrigger-8845-thread-1)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.SystemLogListener Collection .system
does not exist, disabling logging.
[junit4] 2> 2002257 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions
for {
[junit4] 2> "id":"41c325af7201beT3x1soud8hai70iqvybkylqxs5",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":18510440110883262,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[18510440110883262],
[junit4] 2> "_enqueue_time_":18510442112481998,
[junit4] 2> "nodeNames":["127.0.0.1:39852_solr"]}}
[junit4] 2> 2002258 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger:
node_lost_trigger after 5000ms
[junit4] 2> 2002258 DEBUG
(AutoscalingActionExecutor-8846-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 1
ms for event id=41c325af7201beT3x1soud8hai70iqvybkylqxs5
[junit4] 2> 2002260 INFO (qtp870656928-27145) [n:127.0.0.1:34705_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> 2002262 INFO (qtp386038279-27138) [n:127.0.0.1:44300_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> 2002262 DEBUG (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2002263 INFO (qtp870656928-27137) [n:127.0.0.1:34705_solr
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling
params={wt=javabin&version=2} status=0 QTime=4
[junit4] 2> 2002263 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 10
[junit4] 2> 2002263 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes:
[127.0.0.1:44300_solr, 127.0.0.1:34705_solr]
[junit4] 2> 2002263 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 10
[junit4] 2> 2002264 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2002264 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 10, lastZnodeVersion 10
[junit4] 2> 2004263 INFO
(TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[5FDAC3FCD3733791]) [
] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTrigger
[junit4] 2> 2004290 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.SolrTestCaseJ4 ###Starting testSearchRate
[junit4] 2> 2004291 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 11
[junit4] 2> 2004291 DEBUG
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing
/autoscaling.json with znode version 11
[junit4] 2> 2004291 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger
updates upto znodeVersion 11
[junit4] 2> 2004293 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeLost markers
[junit4] 2> 2004294 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old
nodeAdded markers
[junit4] 2> 2004294 DEBUG
(OverseerAutoScalingTriggerThread-73270693535809542-127.0.0.1:34705_solr-n_0000000000)
[n:127.0.0.1:34705_solr ] o.a.s.c.a.OverseerTriggerThread Current
znodeVersion 11, lastZnodeVersion 11
[junit4] 2> 2004295 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2004300 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2004300 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2004300 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2004301 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@45502b87{/solr,null,AVAILABLE}
[junit4] 2> 2004301 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@5e57ce66{HTTP/1.1,[http/1.1]}{127.0.0.1:57537}
[junit4] 2> 2004301 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server Started @2006132ms
[junit4] 2> 2004301 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=57537}
[junit4] 2> 2004302 ERROR
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2004302 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2004302 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2004302 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2004302 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:53.495Z
[junit4] 2> 2004304 INFO (zkConnectionManagerCallback-7273-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004305 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2004314 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 2004316 INFO (zkConnectionManagerCallback-7277-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004319 INFO
(zkConnectionManagerCallback-7279-thread-1-processing-n:127.0.0.1:57537_solr)
[n:127.0.0.1:57537_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004328 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (2)
[junit4] 2> 2004331 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2004334 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:57537_solr
[junit4] 2> 2004336 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2004337 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2004338 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2004345 INFO
(zkCallback-7278-thread-1-processing-n:127.0.0.1:57537_solr)
[n:127.0.0.1:57537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (2) -> (3)
[junit4] 2> 2004447 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_57537.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004457 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_57537.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004458 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_57537.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004459 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:57537_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node5/.
[junit4] 2> 2004497 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2004498 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2004498 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2004498 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2004498 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@35a74087{/solr,null,AVAILABLE}
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@3604657{HTTP/1.1,[http/1.1]}{127.0.0.1:49308}
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server Started @2006330ms
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=49308}
[junit4] 2> 2004499 ERROR
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2004499 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:53.692Z
[junit4] 2> 2004501 INFO (zkConnectionManagerCallback-7283-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004502 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2004511 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 2004512 INFO (zkConnectionManagerCallback-7287-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004515 INFO
(zkConnectionManagerCallback-7289-thread-1-processing-n:127.0.0.1:49308_solr)
[n:127.0.0.1:49308_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004520 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (0) -> (3)
[junit4] 2> 2004522 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2004524 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.c.ZkController Register node as live in
ZooKeeper:/live_nodes/127.0.0.1:49308_solr
[junit4] 2> 2004524 INFO
(zkCallback-7238-thread-1-processing-n:127.0.0.1:44300_solr)
[n:127.0.0.1:44300_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 2004525 INFO
(zkCallback-7240-thread-1-processing-n:127.0.0.1:34705_solr)
[n:127.0.0.1:34705_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 2004525 INFO (zkCallback-7250-thread-1) [ ]
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2004528 INFO
(zkCallback-7288-thread-1-processing-n:127.0.0.1:49308_solr)
[n:127.0.0.1:49308_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 2004528 INFO
(zkCallback-7278-thread-1-processing-n:127.0.0.1:57537_solr)
[n:127.0.0.1:57537_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from
ZooKeeper... (3) -> (4)
[junit4] 2> 2004594 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_49308.solr.node' (registry 'solr.node') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004604 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_49308.solr.jvm' (registry 'solr.jvm') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004604 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for
'solr_49308.solr.jetty' (registry 'solr.jetty') enabled at server:
com.sun.jmx.mbeanserver.JmxMBeanServer@348c658b
[junit4] 2> 2004606 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791])
[n:127.0.0.1:49308_solr ] o.a.s.c.CorePropertiesLocator Found 0 core
definitions underneath
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001/tempDir-001/node6/.
[junit4] 2> 2004650 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp:
2017-11-22T08:27:37+11:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 2004656 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2004656 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2004656 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 2004657 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.h.ContextHandler Started
o.e.j.s.ServletContextHandler@2b7c5a77{/solr,null,AVAILABLE}
[junit4] 2> 2004658 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.AbstractConnector Started
ServerConnector@50654140{HTTP/1.1,[http/1.1]}{127.0.0.1:34896}
[junit4] 2> 2004658 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.e.j.s.Server Started @2006489ms
[junit4] 2> 2004658 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr,
hostPort=34896}
[junit4] 2> 2004658 ERROR
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be
missing or incomplete.
[junit4] 2> 2004658 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version
7.3.0
[junit4] 2> 2004659 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2004659 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2004659 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time:
2018-02-10T10:28:53.852Z
[junit4] 2> 2004661 INFO (zkConnectionManagerCallback-7293-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004661 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2004669 INFO
(TEST-TriggerIntegrationTest.testSearchRate-seed#[5FDAC3FCD3733791]) [ ]
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:54329/solr
[junit4] 2> 2004670 INFO (zkConnectionManagerCallback-7297-thread-1) [
] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2004672 INFO
(zkConnectionManagerCallback-7299-thread-1-processing-n:127.0.0.1:34896_solr)
[n:127.0.0.1:34896_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[juni
[...truncated too long message...]
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.util.concurrent.ConcurrentHashMap$KeySetView.forEach(ConcurrentHashMap.java:4649)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.refreshLiveNodes(ZkStateReader.java:703)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader.access$900(ZkStateReader.java:72)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.refreshAndWatch(ZkStateReader.java:1090)
[junit4] 2> at
org.apache.solr.common.cloud.ZkStateReader$LiveNodeWatcher.process(ZkStateReader.java:1085)
[junit4] 2> at
org.apache.solr.common.cloud.SolrZkClient$1.lambda$process$1(SolrZkClient.java:269)
[junit4] 2> at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at
java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 2199944 WARN
(zkCallback-7403-thread-3-processing-n:127.0.0.1:54293_solr)
[n:127.0.0.1:54293_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered,
but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2199944 INFO (jetty-closer-7223-thread-9) [ ]
o.e.j.s.h.ContextHandler Stopped
o.e.j.s.ServletContextHandler@5851fb60{/solr,null,UNAVAILABLE}
[junit4] 2> 2199944 INFO (jetty-closer-7223-thread-9) [ ]
o.e.j.s.session Stopped scavenging
[junit4] 2> 2199945 ERROR
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-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> 2199946 INFO
(SUITE-TriggerIntegrationTest-seed#[5FDAC3FCD3733791]-worker) [ ]
o.a.s.c.ZkTestServer connecting to 127.0.0.1:54329 54329
[junit4] 2> 2200040 INFO (Thread-6158) [ ] o.a.s.c.ZkTestServer
connecting to 127.0.0.1:54329 54329
[junit4] 2> 2200041 WARN (Thread-6158) [ ] o.a.s.c.ZkTestServer Watch
limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 30 /solr/collections/collection1/terms/shard1
[junit4] 2> 22 /solr/clusterprops.json
[junit4] 2> 22 /solr/aliases.json
[junit4] 2> 21 /solr/security.json
[junit4] 2> 9 /solr/collections/testMetricTrigger/terms/shard1
[junit4] 2> 9 /solr/configs/conf
[junit4] 2> 2 /solr/collections/testMetricTrigger/terms/shard2
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 89 /solr/collections/collection1/state.json
[junit4] 2> 34 /solr/collections/testMetricTrigger/state.json
[junit4] 2> 22 /solr/clusterstate.json
[junit4] 2> 6 /solr/autoscaling.json
[junit4] 2> 3
/solr/overseer_elect/election/73270693535809574-127.0.0.1:41263_solr-n_0000000011
[junit4] 2> 3
/solr/overseer_elect/election/73270693535809571-127.0.0.1:51978_solr-n_0000000010
[junit4] 2> 3
/solr/collections/collection1/leader_elect/shard1/election/73270693535809559-core_node3-n_0000000001
[junit4] 2> 2
/solr/collections/collection1/leader_elect/shard1/election/73270693535809556-core_node8-n_0000000003
[junit4] 2> 2
/solr/overseer_elect/election/73270693535809577-127.0.0.1:38209_solr-n_0000000012
[junit4] 2> 2
/solr/overseer_elect/election/73270693535809592-127.0.0.1:46171_solr-n_0000000017
[junit4] 2> 2
/solr/overseer_elect/election/73270693535809541-127.0.0.1:44300_solr-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:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.TriggerIntegrationTest_5FDAC3FCD3733791-001
[junit4] 2> Feb 10, 2018 10:32:09 AM
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked
thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene70,
sim=RandomSimilarity(queryNorm=true): {}, locale=pt-PT, timezone=Europe/Brussels
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation
1.8.0_144 (64-bit)/cpus=4,threads=1,free=62112352,total=510132224
[junit4] 2> NOTE: All tests run in this JVM: [BadComponentTest,
TestPivotHelperCode, SystemInfoHandlerTest, TestXIncludeConfig,
ScriptEngineTest, DistributedQueryComponentOptimizationTest, SOLR749Test,
HttpPartitionTest, LeaderFailoverAfterPartitionTest, TestFieldCacheSortRandom,
TestSegmentSorting, TestCorePropertiesReload, TestSystemIdResolver,
UninvertDocValuesMergePolicyTest, SolrGangliaReporterTest,
HighlighterMaxOffsetTest, IndexSchemaTest, TestDistribStateManager,
TestCloudDeleteByQuery, CSVRequestHandlerTest, CollectionStateFormat2Test,
DistributedFacetPivotSmallTest, DirectSolrConnectionTest,
TestManagedStopFilterFactory, TestBulkSchemaConcurrent,
PreAnalyzedUpdateProcessorTest, TestFastLRUCache, TestFunctionQuery,
DistributedMLTComponentTest, RulesTest, LoggingHandlerTest,
TestLegacyFieldCache, PeerSyncTest, AutoAddReplicasPlanActionTest,
ExecutePlanActionTest, TestTrieFacet, QueryEqualityTest, TestSmileRequest,
TestFieldCache, TestSolrIndexConfig, QueryResultKeyTest,
ChaosMonkeySafeLeaderTest, TestNRTOpen,
TestPerFieldSimilarityWithDefaultOverride, PeerSyncReplicationTest,
DistributedIntervalFacetingTest, TestReplicaProperties, LargeFieldTest,
RestartWhileUpdatingTest, TestCursorMarkWithoutUniqueKey,
TestClassicSimilarityFactory, HLLSerializationTest, PrimitiveFieldTypeTest,
CreateRoutedAliasTest, AsyncCallRequestStatusResponseTest, TestSolrJ,
PathHierarchyTokenizerFactoryTest, DeleteNodeTest, SimplePostToolTest,
TestPullReplicaErrorHandling, QueryParsingTest, TestReplicationHandler,
TestReload, TestNamedUpdateProcessors, SolrIndexMetricsTest,
TestCollectionsAPIViaSolrCloudCluster, TestRawTransformer,
CdcrVersionReplicationTest, TestHdfsUpdateLog, TestElisionMultitermQuery,
TestImplicitCoreProperties, TestConfigSetsAPIExclusivity,
TestComplexPhraseLeadingWildcard, HdfsNNFailoverTest,
TestSubQueryTransformerDistrib, TestStressRecovery, TestJsonRequest,
StatsReloadRaceTest, DocValuesNotIndexedTest, SortByFunctionTest,
DirectUpdateHandlerOptimizeTest, TestCloudPivotFacet, UpdateLogTest,
TestSurroundQueryParser, TestNumericRangeQuery64, SolrCloudExampleTest,
MoveReplicaHDFSFailoverTest, TestRTGBase, TestReloadDeadlock,
OverriddenZkACLAndCredentialsProvidersTest, LegacyCloudClusterPropTest,
SmileWriterTest, AutoscalingHistoryHandlerTest, MultiThreadedOCPTest,
TestRebalanceLeaders, TestManagedSchemaAPI, TestLeaderInitiatedRecoveryThread,
TestLegacyTerms, PolyFieldTest, SpatialHeatmapFacetsTest, SolrInfoBeanTest,
UpdateRequestProcessorFactoryTest, ConfigSetsAPITest, MetricUtilsTest,
TestSolrCloudWithSecureImpersonation, TestPartialUpdateDeduplication,
HttpSolrCallGetCoreTest, SuggesterFSTTest, OverseerTest, ZkStateWriterTest,
TestRestManager, ZkControllerTest, HdfsRestartWhileUpdatingTest, FileUtilsTest,
TestJavabinTupleStreamParser, SyncSliceTest, TestQueryUtils,
CdcrReplicationDistributedZkTest, TestBM25SimilarityFactory, SearchHandlerTest,
SaslZkACLProviderTest, TestConfigsApi, TestCoreBackup, TestStressLiveNodes,
TestSkipOverseerOperations, ClassificationUpdateProcessorIntegrationTest,
TestZkChroot, TestDistributedSearch, DistributedTermsComponentTest,
StatsComponentTest, TestIndexSearcher, ShowFileRequestHandlerTest,
SolrIndexSplitterTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest,
SignatureUpdateProcessorFactoryTest, TestFoldingMultitermQuery, SuggesterTest,
TestTrie, SuggesterWFSTTest, TestUpdate, FieldMutatingUpdateProcessorTest,
StatelessScriptUpdateProcessorFactoryTest, CacheHeaderTest,
TestReversedWildcardFilterFactory, TermsComponentTest, TestValueSourceCache,
TestIndexingPerformance, RequiredFieldsTest, FastVectorHighlighterTest,
RegexBoostProcessorTest, TestJmxIntegration, MBeansHandlerTest,
TestSimpleTrackingShardHandler, AddReplicaTest,
AssignBackwardCompatibilityTest, ChaosMonkeySafeLeaderWithPullReplicasTest,
CollectionsAPISolrJTest, MoveReplicaTest, ReplaceNodeTest,
TestCloudInspectUtil, TestCloudPseudoReturnFields, TestCloudSearcherWarming,
TestDeleteCollectionOnDownNodes, TestExclusionRuleCollectionAccess,
TestOnReconnectListenerSupport, TestRandomRequestDistribution,
TestTolerantUpdateProcessorCloud, TestTolerantUpdateProcessorRandomCloud,
TestUtilizeNode, TriLevelCompositeIdRoutingTest, ZkFailoverTest,
AutoAddReplicasIntegrationTest, TriggerIntegrationTest]
[junit4] Completed [607/774 (1!)] on J1 in 210.91s, 14 tests, 1 failure <<<
FAILURES!
[...truncated 48787 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
