You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2018/02/23 10:07:27 UTC
[JENKINS] Lucene-Solr-Tests-master - Build # 2362 - Still Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2362/
2 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate
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([3ED79B0344BF6E99:639F858A8B79C8D6]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.sim.TestTriggerIntegration.testSearchRate(TestTriggerIntegration.java:1179)
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)
FAILED: org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory
Error Message:
expected:<5> but was:<0>
Stack Trace:
java.lang.AssertionError: expected:<5> but was:<0>
at __randomizedtesting.SeedInfo.seed([3ED79B0344BF6E99:532B3FFEFEF7919E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest.testHistory(AutoscalingHistoryHandlerTest.java:313)
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 12729 lines...]
[junit4] Suite: org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest
[junit4] 2> 1457323 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/init-core-data-001
[junit4] 2> 1457341 WARN (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 1457342 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 1457343 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 1457344 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001
[junit4] 2> 1457344 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1457382 INFO (Thread-987) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1457382 INFO (Thread-987) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1457418 ERROR (Thread-987) [ ] 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> 1457487 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35096
[junit4] 2> 1457517 INFO (zkConnectionManagerCallback-857-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457531 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T11:27:37-10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1457548 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T11:27:37-10:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1457560 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1457560 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1457560 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1457560 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@38c86ea6{/solr,null,AVAILABLE}
[junit4] 2> 1457561 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4bc9ef7a{HTTP/1.1,[http/1.1]}{127.0.0.1:44022}
[junit4] 2> 1457561 INFO (jetty-launcher-854-thread-1) [ ] o.e.j.s.Server Started @1467901ms
[junit4] 2> 1457561 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44022}
[junit4] 2> 1457562 ERROR (jetty-launcher-854-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1457562 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1457562 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1457562 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1457562 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T08:29:09.561Z
[junit4] 2> 1457577 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1457577 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@469083e1{/solr,null,AVAILABLE}
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@12681a01{HTTP/1.1,[http/1.1]}{127.0.0.1:36426}
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.e.j.s.Server Started @1467918ms
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36426}
[junit4] 2> 1457578 ERROR (jetty-launcher-854-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1457578 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1457579 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1457579 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1457579 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T08:29:09.578Z
[junit4] 2> 1457645 INFO (zkConnectionManagerCallback-859-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457645 INFO (zkConnectionManagerCallback-861-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457670 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1457670 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1457702 INFO (jetty-launcher-854-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35096/solr
[junit4] 2> 1457737 INFO (jetty-launcher-854-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35096/solr
[junit4] 2> 1457751 INFO (zkConnectionManagerCallback-865-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457753 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 0x100660a49ef0003, likely client has closed socket
[junit4] 2> 1457767 INFO (zkConnectionManagerCallback-869-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457787 INFO (zkConnectionManagerCallback-871-thread-1-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457817 INFO (zkConnectionManagerCallback-873-thread-1-processing-n:127.0.0.1:44022_solr) [n:127.0.0.1:44022_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1457975 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1457975 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36426_solr
[junit4] 2> 1457976 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer Overseer (id=72169788414033925-127.0.0.1:36426_solr-n_0000000000) starting
[junit4] 2> 1458144 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer Starting to work on the main queue
[junit4] 2> 1458145 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36426_solr
[junit4] 2> 1458146 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1458147 INFO (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1458193 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1458193 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:36426_solr]
[junit4] 2> 1458193 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1458193 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1458198 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1458198 DEBUG (OverseerAutoScalingTriggerThread-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1458199 DEBUG (ScheduledTrigger-1367-thread-1) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1458447 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1458466 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1458468 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44022_solr
[junit4] 2> 1458514 INFO (zkCallback-870-thread-1-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1458515 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"downnode",
[junit4] 2> "node_name":"127.0.0.1:44022_solr"} current state version: 0
[junit4] 2> 1458515 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:44022_solr
[junit4] 2> 1458535 INFO (zkCallback-872-thread-1-processing-n:127.0.0.1:44022_solr) [n:127.0.0.1:44022_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1458694 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36426.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458764 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36426.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458764 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36426.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458778 INFO (jetty-launcher-854-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node2/.
[junit4] 2> 1458934 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44022.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458970 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44022.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458970 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44022.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1458983 INFO (jetty-launcher-854-thread-1) [n:127.0.0.1:44022_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/.
[junit4] 2> 1459049 INFO (zkConnectionManagerCallback-879-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1459085 INFO (zkConnectionManagerCallback-883-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1459087 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1459087 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35096/solr ready
[junit4] 2> 1459109 INFO (qtp913925118-4066) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:36426_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1459162 INFO (OverseerThreadFactory-1369-thread-1-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 1459176 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":".system",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "numShards":1,
[junit4] 2> "createNodeSet":"127.0.0.1:36426_solr",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 1459176 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: .system
[junit4] 2> 1459176 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/.system/state.json
[junit4] 2> 1459206 DEBUG (ScheduledTrigger-1367-thread-1) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1459341 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1459341 INFO (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1459342 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 1459342 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1459479 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 0
[junit4] 2> 1459608 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1459608 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1459702 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1459702 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 1459702 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:36426/solr","node_name":"127.0.0.1:36426_solr","state":"down","type":"NRT"}
[junit4] 2> 1459702 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1459815 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 1
[junit4] 2> 1459817 INFO (zkCallback-870-thread-1-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1459817 INFO (zkCallback-870-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1460212 DEBUG (ScheduledTrigger-1367-thread-2) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1460760 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 1460781 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 1460796 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 1460817 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 1460831 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 1460833 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 1460833 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from collection .system, trusted=true
[junit4] 2> 1460834 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36426.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7fe25c83
[junit4] 2> 1460834 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1460834 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node2/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 1461180 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1461180 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1461181 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommited docs
[junit4] 2> 1461181 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1461199 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f860d21[.system_shard1_replica_n1] main]
[junit4] 2> 1461213 DEBUG (ScheduledTrigger-1367-thread-1) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1461220 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 1461220 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 1461221 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 1461221 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 1461222 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 1461223 INFO (searcherExecutor-1374-thread-1-processing-n:127.0.0.1:36426_solr x:.system_shard1_replica_n1 s:shard1 c:.system r:core_node2) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@1f860d21[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1461223 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1593179691519311872
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36426/solr/.system_shard1_replica_n1/
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36426/solr/.system_shard1_replica_n1/ has no replicas
[junit4] 2> 1461237 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1461253 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36426/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 1461253 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"leader",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"active"} current state version: 0
[junit4] 2> 1461354 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 2
[junit4] 2> 1461354 INFO (zkCallback-870-thread-3-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1461354 INFO (zkCallback-870-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1461404 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1461405 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1461405 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":".system",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 1461405 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:36426/solr","node_name":"127.0.0.1:36426_solr","state":"active","type":"NRT","leader":"true"}
[junit4] 2> 1461405 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/3)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"1",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"1",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"1",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node2":{
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:36426/solr",
[junit4] 2> "node_name":"127.0.0.1:36426_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true"}}}}}
[junit4] 2> 1461405 INFO (qtp747239503-4077) [n:127.0.0.1:36426_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1797
[junit4] 2> 1461408 INFO (qtp913925118-4066) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 1461506 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 3
[junit4] 2> 1461506 INFO (zkCallback-870-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1461506 INFO (zkCallback-870-thread-3-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1462213 DEBUG (ScheduledTrigger-1367-thread-1) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1462409 INFO (qtp913925118-4066) [n:127.0.0.1:44022_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:36426_solr&wt=javabin&version=2} status=0 QTime=3299
[junit4] 2> 1462410 INFO (qtp913925118-4068) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=3&maxShardsPerNode=3&name=AutoscalingHistoryHandlerTest_collection&nrtReplicas=3&action=CREATE&numShards=1&createNodeSet=127.0.0.1:44022_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1462412 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection AutoscalingHistoryHandlerTest_collection
[junit4] 2> 1462413 INFO (OverseerCollectionConfigSetProcessor-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_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> 1462413 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/protwords.txt
[junit4] 2> 1462414 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/managed-schema
[junit4] 2> 1462416 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/solrconfig.xml
[junit4] 2> 1462417 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/synonyms.txt
[junit4] 2> 1462418 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/stopwords.txt
[junit4] 2> 1462420 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/params.json to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/params.json
[junit4] 2> 1462421 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_it.txt
[junit4] 2> 1462422 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_no.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_no.txt
[junit4] 2> 1462424 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hy.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hy.txt
[junit4] 2> 1462433 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stemdict_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stemdict_nl.txt
[junit4] 2> 1462434 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ca.txt
[junit4] 2> 1462435 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_id.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_id.txt
[junit4] 2> 1462437 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ga.txt
[junit4] 2> 1462438 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_da.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_da.txt
[junit4] 2> 1462439 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hi.txt
[junit4] 2> 1462440 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ja.txt
[junit4] 2> 1462442 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_pt.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_pt.txt
[junit4] 2> 1462443 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hu.txt
[junit4] 2> 1462444 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_el.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_el.txt
[junit4] 2> 1462445 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ru.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ru.txt
[junit4] 2> 1462447 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_tr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_tr.txt
[junit4] 2> 1462448 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ar.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ar.txt
[junit4] 2> 1462457 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/userdict_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/userdict_ja.txt
[junit4] 2> 1462458 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_it.txt
[junit4] 2> 1462460 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_eu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_eu.txt
[junit4] 2> 1462461 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_cz.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_cz.txt
[junit4] 2> 1462462 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stoptags_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stoptags_ja.txt
[junit4] 2> 1462509 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_fr.txt
[junit4] 2> 1462510 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fa.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fa.txt
[junit4] 2> 1462512 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_de.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_de.txt
[junit4] 2> 1462513 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ga.txt
[junit4] 2> 1462527 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ca.txt
[junit4] 2> 1462528 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_nl.txt
[junit4] 2> 1462529 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_bg.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_bg.txt
[junit4] 2> 1462534 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_es.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_es.txt
[junit4] 2> 1462536 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_en.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_en.txt
[junit4] 2> 1462538 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_lv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_lv.txt
[junit4] 2> 1462547 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_th.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_th.txt
[junit4] 2> 1462548 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ro.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ro.txt
[junit4] 2> 1462550 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fr.txt
[junit4] 2> 1462551 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_sv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_sv.txt
[junit4] 2> 1462552 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fi.txt
[junit4] 2> 1462554 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/hyphenations_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/hyphenations_ga.txt
[junit4] 2> 1462555 INFO (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_gl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_gl.txt
[junit4] 2> 1462556 WARN (OverseerThreadFactory-1369-thread-2-processing-n:127.0.0.1:36426_solr) [n:127.0.0.1:36426_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection AutoscalingHistoryHandlerTest_collection is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 1462561 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "name":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "numShards":"1",
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "createNodeSet":"127.0.0.1:44022_solr",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "stateFormat":"2",
[junit4] 2> "operation":"create"} current state version: 0
[junit4] 2> 1462561 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: AutoscalingHistoryHandlerTest_collection
[junit4] 2> 1462661 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json
[junit4] 2> 1462765 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1462765 INFO (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1462766 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{}}
[junit4] 2> 1462766 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1462767 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 2, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1462767 INFO (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1462768 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{"core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1462768 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1462795 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"} current state version: 0
[junit4] 2> 1462795 INFO (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 1462797 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1462797 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node6":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}
[junit4] 2> 1462898 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json version: 0
[junit4] 2> 1462998 INFO (qtp913925118-4071) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1462999 INFO (qtp913925118-4065) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n4&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1462999 INFO (qtp913925118-4071) [n:127.0.0.1:44022_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1462999 INFO (qtp913925118-4141) [n:127.0.0.1:44022_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=AutoscalingHistoryHandlerTest_collection.AUTOCREATED&newCollection=true&name=AutoscalingHistoryHandlerTest_collection_shard1_replica_n2&action=CREATE&numShards=1&collection=AutoscalingHistoryHandlerTest_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 1463004 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1463004 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 1463004 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node3:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1","base_url":"http://127.0.0.1:44022/solr","node_name":"127.0.0.1:44022_solr","state":"down","type":"NRT"}
[junit4] 2> 1463004 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node6":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1463005 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node5",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1463005 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "core_node_name":"core_node5",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 1463005 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node5:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2","base_url":"http://127.0.0.1:44022/solr","node_name":"127.0.0.1:44022_solr","state":"down","type":"NRT"}
[junit4] 2> 1463005 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node6":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "state":"down",
[junit4] 2> "node_name":null,
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1463013 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.Overseer processMessage: queueSize: 3, message = {
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "core_node_name":"core_node6",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"} current state version: 0
[junit4] 2> 1463013 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "core_node_name":"core_node6",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"AutoscalingHistoryHandlerTest_collection",
[junit4] 2> "type":"NRT",
[junit4] 2> "operation":"state"}
[junit4] 2> 1463013 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node6:{"core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4","base_url":"http://127.0.0.1:44022/solr","node_name":"127.0.0.1:44022_solr","state":"down","type":"NRT"}
[junit4] 2> 1463013 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(AutoscalingHistoryHandlerTest_collection//collections/AutoscalingHistoryHandlerTest_collection/state.json/1)={
[junit4] 2> "pullReplicas":"0",
[junit4] 2> "replicationFactor":"3",
[junit4] 2> "router":{"name":"compositeId"},
[junit4] 2> "maxShardsPerNode":"3",
[junit4] 2> "autoAddReplicas":"false",
[junit4] 2> "nrtReplicas":"3",
[junit4] 2> "tlogReplicas":"0",
[junit4] 2> "shards":{"shard1":{
[junit4] 2> "range":"80000000-7fffffff",
[junit4] 2> "state":"active",
[junit4] 2> "replicas":{
[junit4] 2> "core_node3":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n1",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node5":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n2",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"},
[junit4] 2> "core_node6":{
[junit4] 2> "core":"AutoscalingHistoryHandlerTest_collection_shard1_replica_n4",
[junit4] 2> "base_url":"http://127.0.0.1:44022/solr",
[junit4] 2> "node_name":"127.0.0.1:44022_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT"}}}}}
[junit4] 2> 1463114 DEBUG (OverseerStateUpdate-72169788414033925-127.0.0.1:36426_solr-n_0000000000) [n:127.0.0.1:36426_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json version: 1
[junit4] 2> 1463115 INFO (zkCallback-872-thread-1-processing-n:127.0.0.1:44022_solr) [n:127.0.0.1:44022_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for collection [AutoscalingHistoryHandlerTest_collection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1463115 INFO (zkCallback-872-thread-2-processing-n:127.0.0.1:44022_solr) [n:127.0.0.1:44022_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/AutoscalingHistoryHandlerTest_collection/state.json] for collection [AutoscalingHistoryHandlerTest_collection] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1463213 DEBUG (ScheduledTrigger-1367-thread-1) [n:127.0.0.1:36426_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1464091 INFO (qtp913925118-4141) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2] o.a.s.c.RequestParams conf resource params.json loaded . version : 0
[junit4] 2> 1464091 INFO (qtp913925118-4141) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2] o.a.s.c.RequestParams request params refreshed to version 0
[junit4] 2> 1464092 WARN (qtp913925118-4141) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n2/../../../../contrib/extraction/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n2/../../../../contrib/extraction/lib
[junit4] 2> 1464092 WARN (qtp913925118-4141) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node5 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n2] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n2/../../../../dist filtered by solr-cell-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n2/../../../../dist
[junit4] 2> 1464108 INFO (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.RequestParams conf resource params.json loaded . version : 0
[junit4] 2> 1464125 INFO (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.RequestParams request params refreshed to version 0
[junit4] 2> 1464126 WARN (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../contrib/extraction/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../contrib/extraction/lib
[junit4] 2> 1464126 WARN (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../dist filtered by solr-cell-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../dist
[junit4] 2> 1464126 WARN (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../contrib/clustering/lib filtered by .*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../contrib/clustering/lib
[junit4] 2> 1464126 WARN (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../dist filtered by solr-clustering-\d.*\.jar to classpath: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_3ED79B0344BF6E99-001/tempDir-001/node1/AutoscalingHistoryHandlerTest_collection_shard1_replica_n1/../../../../dist
[junit4] 2> 1464126 WARN (qtp913925118-4071) [n:127.0.0.1:44022_solr c:AutoscalingHistoryHandlerTest_collection s:shard1 r:core_node3 x:AutoscalingHistoryHandlerTest_collection_shard1_replica_n1] o.a.s.c.SolrConfig Couldn't add files from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.handler.a
[...truncated too long message...]
38-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"628a1d3435ca3T5c0i5po49rkbm5n07q4g7po04",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1733525359516835,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1733525359516835],
[junit4] 2> "nodeNames":["127.0.0.1:10022_solr"]}}
[junit4] 2> 2807474 DEBUG (ScheduledTrigger-4438-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_trigger]
[junit4] 2> 2807485 DEBUG (AutoscalingActionExecutor-4439-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"628a1d3435ca3T5c0i5po49rkbm5n07q4g7po04",
[junit4] 2> "source":"node_added_trigger",
[junit4] 2> "eventTime":1733525359516835,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[1733525359516835],
[junit4] 2> "_enqueue_time_":1733530263900585,
[junit4] 2> "nodeNames":["127.0.0.1:10022_solr"]}}
[junit4] 2> 2807506 DEBUG (AutoscalingActionExecutor-4439-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 2807506 DEBUG (AutoscalingActionExecutor-4439-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_trigger after 100ms
[junit4] 2> 2807506 DEBUG (AutoscalingActionExecutor-4439-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 1026 ms for event id=628a1d3435ca3T5c0i5po49rkbm5n07q4g7po04
[junit4] 2> 2807506 DEBUG (simCloudManagerPool-4437-thread-3) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 2807506 DEBUG (simCloudManagerPool-4437-thread-3) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 45
[junit4] 2> 2807506 DEBUG (simCloudManagerPool-4437-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10022_solr, 127.0.0.1:10021_solr, 127.0.0.1:10019_solr]
[junit4] 2> 2807506 DEBUG (simCloudManagerPool-4437-thread-3) [ ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:10022_solr, 127.0.0.1:10021_solr, 127.0.0.1:10019_solr]
[junit4] 2> 2807506 DEBUG (simCloudManagerPool-4437-thread-3) [ ] 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.sim.TestTriggerIntegration$TestTriggerAction}], enabled=true}
[junit4] 2> 2807506 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 45
[junit4] 2> 2807507 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 45, lastZnodeVersion 45
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeAddedTrigger
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase
[junit4] 2>
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ############ FINAL CLUSTER STATS ############
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase #############################################
[junit4] 2>
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Live nodes: 3
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Empty nodes: 3
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Dead nodes: 0
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Collections: []
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Max replicas per node: 0
[junit4] 2> 2807554 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Min replicas per node: 0
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 0
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 2
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 2
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 1
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 1
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: search_rate_trigger
[junit4] 2> 2807555 INFO (TEST-TestTriggerIntegration.testNodeAddedTrigger-seed#[3ED79B0344BF6E99]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - FAILED 1
[junit4] 2> 2807555 DEBUG (SUITE-TestTriggerIntegration-seed#[3ED79B0344BF6E99]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestTriggerIntegration_3ED79B0344BF6E99-001
[junit4] 2> 2807557 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@3a5af99a), locale=zh, timezone=NET
[junit4] 2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_152 (64-bit)/cpus=4,threads=1,free=202645352,total=529530880
[junit4] 2> NOTE: All tests run in this JVM: [AutoAddReplicasIntegrationTest, HdfsDirectoryTest, DeleteInactiveReplicaTest, TestSolrCloudWithKerberosAlt, UUIDUpdateProcessorFallbackTest, CollectionsAPIDistributedZkTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestDirectoryFactory, TestJavabinTupleStreamParser, CacheHeaderTest, SaslZkACLProviderTest, HdfsChaosMonkeySafeLeaderTest, TestCollectionAPI, TestLegacyTerms, TestStressInPlaceUpdates, TestSchemaNameResource, TestPolicyCloud, TestNamedUpdateProcessors, TestRandomDVFaceting, SchemaApiFailureTest, ClusterStateTest, MultiTermTest, DistributedFacetSimpleRefinementLongTailTest, TestDynamicFieldCollectionResource, TestReloadDeadlock, CoreMergeIndexesAdminHandlerTest, TestJmxIntegration, TestDeleteCollectionOnDownNodes, ShowFileRequestHandlerTest, TestSchemaVersionResource, AutoscalingHistoryHandlerTest, MultiThreadedOCPTest, PreAnalyzedFieldTest, TestTolerantUpdateProcessorCloud, DistributedQueueTest, TestSolrCLIRunExample, CollectionReloadTest, TestFiltering, TestSolrCoreProperties, SolrCloudExampleTest, SpellCheckComponentTest, URLClassifyProcessorTest, MoveReplicaHDFSFailoverTest, EnumFieldTest, HdfsCollectionsAPIDistributedZkTest, JvmMetricsTest, DeleteReplicaTest, LeaderFailoverAfterPartitionTest, TestSolrFieldCacheBean, LeaderElectionIntegrationTest, DistributedQueryComponentOptimizationTest, DistributedFacetPivotLargeTest, TestDownShardTolerantSearch, LargeFieldTest, TestUtils, TestCloudSearcherWarming, SearchHandlerTest, TlogReplayBufferedWhileIndexingTest, DistributedSpellCheckComponentTest, TestExportWriter, TestNoOpRegenerator, InfixSuggestersTest, BadCopyFieldTest, TestFieldCache, TestConfigOverlay, TestCollationFieldDocValues, ConvertedLegacyTest, UnloadDistributedZkTest, TestRestManager, TestRuleBasedAuthorizationPlugin, BlockJoinFacetSimpleTest, TestComputePlanAction, DocValuesMultiTest, LegacyCloudClusterPropTest, ClusterStateUpdateTest, CollectionsAPISolrJTest, TestNestedDocsSort, TestMiniSolrCloudClusterSSL, SolrCmdDistributorTest, TestRealTimeGet, LeaderElectionTest, SpellCheckCollatorWithCollapseTest, SolrShardReporterTest, CircularListTest, PeerSyncReplicationTest, TestLRUStatsCache, TestCodecSupport, SpatialFilterTest, ResponseLogComponentTest, AtomicUpdateProcessorFactoryTest, TestTriggerIntegration]
[junit4] Completed [360/778 (2!)] on J2 in 7.09s, 11 tests, 1 failure <<< FAILURES!
[...truncated 51466 lines...]
[JENKINS] Lucene-Solr-Tests-master - Build # 2363 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/2363/
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardRoutingTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardRoutingTest: 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardRoutingTest:
1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([24B4BD63E0209CAF]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.ShardRoutingTest
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308) at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) at java.lang.Thread.run(Thread.java:748)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
at java.lang.Thread.run(Thread.java:748)
at __randomizedtesting.SeedInfo.seed([24B4BD63E0209CAF]:0)
FAILED: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventQueue
Error Message:
action wasn't interrupted
Stack Trace:
java.lang.AssertionError: action wasn't interrupted
at __randomizedtesting.SeedInfo.seed([24B4BD63E0209CAF:ED01FFCDE9475A5A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.TriggerIntegrationTest.testEventQueue(TriggerIntegrationTest.java:726)
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 13112 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.TriggerIntegrationTest
[junit4] 2> 1054845 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-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-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/init-core-data-001
[junit4] 2> 1054846 WARN (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=44 numCloses=44
[junit4] 2> 1054846 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 1054847 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 1054847 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001
[junit4] 2> 1054847 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1054848 INFO (Thread-1686) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1054848 INFO (Thread-1686) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1054885 ERROR (Thread-1686) [ ] 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> 1054984 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:59445
[junit4] 2> 1055007 INFO (zkConnectionManagerCallback-1506-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055020 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1055020 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1055049 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1055049 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1055050 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1055050 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1055050 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1055050 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1055050 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1d8228ab{/solr,null,AVAILABLE}
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@16189cb7{HTTP/1.1,[http/1.1]}{127.0.0.1:51188}
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.e.j.s.Server Started @1057496ms
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=51188}
[junit4] 2> 1055051 ERROR (jetty-launcher-1503-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1055051 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T13:53:23.630Z
[junit4] 2> 1055052 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6824a107{/solr,null,AVAILABLE}
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@400ad194{HTTP/1.1,[http/1.1]}{127.0.0.1:38443}
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.e.j.s.Server Started @1057498ms
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38443}
[junit4] 2> 1055053 ERROR (jetty-launcher-1503-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1055053 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T13:53:23.632Z
[junit4] 2> 1055053 INFO (zkConnectionManagerCallback-1508-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055054 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1055060 INFO (zkConnectionManagerCallback-1510-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055061 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1055066 INFO (jetty-launcher-1503-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59445/solr
[junit4] 2> 1055068 INFO (jetty-launcher-1503-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59445/solr
[junit4] 2> 1055097 INFO (zkConnectionManagerCallback-1514-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055104 INFO (zkConnectionManagerCallback-1518-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055105 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 0x10492fcce770004, likely client has closed socket
[junit4] 2> 1055107 INFO (zkConnectionManagerCallback-1520-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055144 INFO (zkConnectionManagerCallback-1522-thread-1-processing-n:127.0.0.1:38443_solr) [n:127.0.0.1:38443_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055163 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1055164 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38443_solr
[junit4] 2> 1055165 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1055165 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.Overseer Overseer (id=73345108438089734-127.0.0.1:38443_solr-n_0000000000) starting
[junit4] 2> 1055166 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51188_solr
[junit4] 2> 1055194 INFO (zkCallback-1521-thread-1-processing-n:127.0.0.1:38443_solr) [n:127.0.0.1:38443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1055194 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1055218 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1055218 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38443_solr
[junit4] 2> 1055219 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1055219 INFO (zkCallback-1521-thread-1-processing-n:127.0.0.1:38443_solr) [n:127.0.0.1:38443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1055233 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 1055233 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:51188_solr, 127.0.0.1:38443_solr]
[junit4] 2> 1055233 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion -1
[junit4] 2> 1055233 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 1055241 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1055241 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 1055242 DEBUG (ScheduledTrigger-2576-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1055277 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51188.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055285 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51188.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055285 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_51188.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055286 INFO (jetty-launcher-1503-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001/node2/.
[junit4] 2> 1055436 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38443.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055446 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38443.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055447 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38443.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1055448 INFO (jetty-launcher-1503-thread-1) [n:127.0.0.1:38443_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001/node1/.
[junit4] 2> 1055500 INFO (zkConnectionManagerCallback-1528-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055525 INFO (zkConnectionManagerCallback-1532-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1055525 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1055526 INFO (SUITE-TriggerIntegrationTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:59445/solr ready
[junit4] 2> 1055591 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testContinueTriggersOnOverseerRestart
[junit4] 2> 1055602 INFO (qtp661620047-7989) [n:127.0.0.1:38443_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1055612 INFO (qtp661620047-7989) [n:127.0.0.1:38443_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=10
[junit4] 2> 1055613 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers -- removing trigger: .auto_add_replicas
[junit4] 2> 1055616 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 2
[junit4] 2> 1055616 DEBUG (zkCallback-1521-thread-1-processing-n:127.0.0.1:38443_solr) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 1055617 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 1055617 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1055617 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1055617 DEBUG (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 1055617 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1055628 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@400ad194{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1055629 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=431809488
[junit4] 2> 1055629 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1055629 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@614c235a: rootName = solr_38443, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@26112656
[junit4] 2> 1055636 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1055636 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@25e7f6c2: rootName = solr_38443, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@4ec2a71
[junit4] 2> 1055640 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1055640 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@457d0b5f: rootName = solr_38443, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6adeaf91
[junit4] 2> 1055642 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:38443_solr
[junit4] 2> 1055642 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1055643 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1055643 INFO (zkCallback-1521-thread-1-processing-n:127.0.0.1:38443_solr) [n:127.0.0.1:38443_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1055645 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1055649 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.Overseer Overseer (id=73345108438089734-127.0.0.1:38443_solr-n_0000000000) closing
[junit4] 2> 1055649 INFO (OverseerStateUpdate-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:38443_solr
[junit4] 2> 1055650 DEBUG (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1055650 WARN (OverseerAutoScalingTriggerThread-73345108438089734-127.0.0.1:38443_solr-n_0000000000) [n:127.0.0.1:38443_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1055651 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1055651 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1055652 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:51188_solr
[junit4] 2> 1055652 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6824a107{/solr,null,UNAVAILABLE}
[junit4] 2> 1055652 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1055653 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.Overseer Overseer (id=73345108438089733-127.0.0.1:51188_solr-n_0000000001) starting
[junit4] 2> 1055665 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1055666 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 1055666 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:51188_solr]
[junit4] 2> 1055666 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion -1
[junit4] 2> 1055666 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 1055669 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1055669 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 1055669 DEBUG (ScheduledTrigger-2585-thread-1) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1056673 DEBUG (ScheduledTrigger-2585-thread-1) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1057674 DEBUG (ScheduledTrigger-2585-thread-2) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1058674 DEBUG (ScheduledTrigger-2585-thread-1) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1059674 DEBUG (ScheduledTrigger-2585-thread-1) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1060654 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1060655 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1060655 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1060656 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1060656 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3d310d8f{/solr,null,AVAILABLE}
[junit4] 2> 1060657 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5e06b1e3{HTTP/1.1,[http/1.1]}{127.0.0.1:32850}
[junit4] 2> 1060657 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server Started @1063102ms
[junit4] 2> 1060657 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=32850}
[junit4] 2> 1060657 ERROR (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1060658 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1060658 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1060658 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1060658 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T13:53:29.237Z
[junit4] 2> 1060662 INFO (zkConnectionManagerCallback-1535-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1060663 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1060673 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59445/solr
[junit4] 2> 1060674 DEBUG (ScheduledTrigger-2585-thread-1) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1060675 INFO (zkConnectionManagerCallback-1539-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1060680 INFO (zkConnectionManagerCallback-1541-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1060691 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1060693 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1060695 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32850_solr
[junit4] 2> 1060697 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1060697 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1060697 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1060705 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1060781 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32850.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1060803 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32850.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1060803 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32850.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1060804 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:32850_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001/node3/.
[junit4] 2> 1060835 INFO (qtp1380633802-8062) [n:127.0.0.1:32850_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1060845 INFO (qtp1380633802-8062) [n:127.0.0.1:32850_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=10
[junit4] 2> 1060849 INFO (qtp1380633802-8067) [n:127.0.0.1:32850_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> 1060851 INFO (qtp319484947-8001) [n:127.0.0.1:51188_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> 1060851 DEBUG (qtp1380633802-8064) [n:127.0.0.1:32850_solr ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 1060855 INFO (qtp1380633802-8064) [n:127.0.0.1:32850_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/autoscaling params={wt=javabin&version=2} status=0 QTime=8
[junit4] 2> 1060855 DEBUG (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 1060856 DEBUG (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:51188_solr, 127.0.0.1:32850_solr]
[junit4] 2> 1060856 DEBUG (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerCTOOR instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true}
[junit4] 2> 1060856 DEBUG (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:51188_solr, 127.0.0.1:32850_solr]
[junit4] 2> 1060856 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 1060857 INFO (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 1060858 DEBUG (ScheduledTrigger-2585-thread-3) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1060858 DEBUG (ScheduledTrigger-2585-thread-3) [n:127.0.0.1:51188_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1060858 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@16189cb7{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1060861 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1760390598
[junit4] 2> 1060861 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1060861 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5a377dec: rootName = solr_51188, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@14b93cb5
[junit4] 2> 1060862 DEBUG (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1060869 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1060869 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@59ad1651: rootName = solr_51188, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@4ec2a71
[junit4] 2> 1060874 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1060874 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@51d99e28: rootName = solr_51188, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6adeaf91
[junit4] 2> 1060875 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:51188_solr
[junit4] 2> 1060875 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1060875 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1060876 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1060876 INFO (zkCallback-1519-thread-1-processing-n:127.0.0.1:51188_solr) [n:127.0.0.1:51188_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1060876 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1060876 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1060877 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.Overseer Overseer (id=73345108438089733-127.0.0.1:51188_solr-n_0000000001) closing
[junit4] 2> 1060877 INFO (OverseerStateUpdate-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:51188_solr
[junit4] 2> 1060878 WARN (OverseerAutoScalingTriggerThread-73345108438089733-127.0.0.1:51188_solr-n_0000000001) [n:127.0.0.1:51188_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1060879 DEBUG (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1060880 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:32850_solr
[junit4] 2> 1060880 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.Overseer Overseer (id=73345108438089739-127.0.0.1:32850_solr-n_0000000002) starting
[junit4] 2> 1060881 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1d8228ab{/solr,null,UNAVAILABLE}
[junit4] 2> 1060881 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1060891 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 1060892 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Initial livenodes: [127.0.0.1:32850_solr]
[junit4] 2> 1060892 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerCTOOR instantiated with properties: {event=nodeAdded, waitFor=2, actions=[{name=test, class=org.apache.solr.cloud.autoscaling.TriggerIntegrationTest$TestTriggerAction}], enabled=true}
[junit4] 2> 1060892 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:32850_solr]
[junit4] 2> 1060892 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion -1
[junit4] 2> 1060892 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 1060893 INFO (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.TriggerIntegrationTest TestTriggerAction init
[junit4] 2> 1060894 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Adding lost node from marker path: 127.0.0.1:51188_solr
[junit4] 2> 1060894 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1060894 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1060894 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 1060895 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1061894 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1061894 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1061895 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1062895 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1062895 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1062896 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1063895 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1063895 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1063896 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1064896 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1064896 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1064896 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1065896 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1065896 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1065896 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1066896 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1066896 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1066896 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1067897 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1067897 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1067897 DEBUG (ScheduledTrigger-2596-thread-1) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1068897 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1068897 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1068897 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1069897 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1069897 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1069897 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1070883 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1070885 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1070885 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1070885 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Scavenging every 660000ms
[junit4] 2> 1070885 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@41521ced{/solr,null,AVAILABLE}
[junit4] 2> 1070886 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@8bb900c{HTTP/1.1,[http/1.1]}{127.0.0.1:41620}
[junit4] 2> 1070886 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server Started @1073331ms
[junit4] 2> 1070886 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41620}
[junit4] 2> 1070886 ERROR (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1070887 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1070887 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1070887 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1070887 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T13:53:39.466Z
[junit4] 2> 1070889 INFO (zkConnectionManagerCallback-1545-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1070889 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1070898 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1070898 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1070898 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 1
[junit4] 2> 1070899 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59445/solr
[junit4] 2> 1070900 INFO (zkConnectionManagerCallback-1549-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1070902 INFO (zkConnectionManagerCallback-1551-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1070908 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1070909 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1070911 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41620_solr
[junit4] 2> 1070917 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1070918 INFO (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1070918 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1070918 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1071013 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41620.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1071023 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41620.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1071023 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41620.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1071025 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:41620_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001/node4/.
[junit4] 2> 1071898 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1071898 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1071898 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1071898 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Tracking new node: 127.0.0.1:41620_solr at time 19645927697246489
[junit4] 2> 1072899 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1072899 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1072899 DEBUG (ScheduledTrigger-2596-thread-3) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1073899 DEBUG (ScheduledTrigger-2596-thread-4) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1073899 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Running NodeAddedTrigger node_added_triggerCTOOR
[junit4] 2> 1073899 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger Found livenodes: 2
[junit4] 2> 1073899 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.NodeAddedTrigger NodeAddedTrigger node_added_triggerCTOOR firing registered processor for nodes: [127.0.0.1:41620_solr] added at times [19645927697246489], now=19645929698525470
[junit4] 2> 1073900 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"45cbddfdad6919T4e30cm4g2feiukpwgx3xg9fbm",
[junit4] 2> "source":"node_added_triggerCTOOR",
[junit4] 2> "eventTime":19645927697246489,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[19645927697246489],
[junit4] 2> "nodeNames":["127.0.0.1:41620_solr"]}}
[junit4] 2> 1073900 DEBUG (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, node_added_triggerCTOOR]
[junit4] 2> 1073901 INFO (ScheduledTrigger-2596-thread-2) [n:127.0.0.1:32850_solr ] o.a.s.c.a.SystemLogListener Collection .system does not exist, disabling logging.
[junit4] 2> 1073902 DEBUG (AutoscalingActionExecutor-2597-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"45cbddfdad6919T4e30cm4g2feiukpwgx3xg9fbm",
[junit4] 2> "source":"node_added_triggerCTOOR",
[junit4] 2> "eventTime":19645927697246489,
[junit4] 2> "eventType":"NODEADDED",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[19645927697246489],
[junit4] 2> "_enqueue_time_":19645929699557281,
[junit4] 2> "nodeNames":["127.0.0.1:41620_solr"]}}
[junit4] 2> 1073902 INFO (TEST-TriggerIntegrationTest.testContinueTriggersOnOverseerRestart-seed#[24B4BD63E0209CAF]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testContinueTriggersOnOverseerRestart
[junit4] 2> 1073907 DEBUG (AutoscalingActionExecutor-2597-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 5000ms
[junit4] 2> 1073908 DEBUG (AutoscalingActionExecutor-2597-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers Resuming trigger: node_added_triggerCTOOR after 5000ms
[junit4] 2> 1073912 DEBUG (AutoscalingActionExecutor-2597-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.a.ScheduledTriggers -- processing took 9 ms for event id=45cbddfdad6919T4e30cm4g2feiukpwgx3xg9fbm
[junit4] 2> 1073921 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSetProperties
[junit4] 2> 1073923 INFO (qtp1380633802-8066) [n:127.0.0.1:32850_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1073928 INFO (qtp1380633802-8066) [n:127.0.0.1:32850_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 1073929 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers -- removing trigger: .auto_add_replicas
[junit4] 2> 1073930 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers -- removing trigger: node_added_triggerCTOOR
[junit4] 2> 1073931 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 5
[junit4] 2> 1073931 DEBUG (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 5
[junit4] 2> 1073931 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 5
[junit4] 2> 1073931 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1073932 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1073932 DEBUG (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 5, lastZnodeVersion 5
[junit4] 2> 1073932 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1073934 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5e06b1e3{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 1073934 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2051132034
[junit4] 2> 1073934 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 1073934 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5802c6e2: rootName = solr_32850, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3645edf
[junit4] 2> 1073941 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 1073941 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6c6bd4ef: rootName = solr_32850, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@4ec2a71
[junit4] 2> 1073945 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 1073945 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1380cab8: rootName = solr_32850, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@6adeaf91
[junit4] 2> 1073946 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:32850_solr
[junit4] 2> 1073947 INFO (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1073948 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1073949 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 1073949 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 1073949 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.Overseer Overseer (id=73345108438089739-127.0.0.1:32850_solr-n_0000000002) closing
[junit4] 2> 1073949 WARN (OverseerAutoScalingTriggerThread-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 1073949 INFO (OverseerStateUpdate-73345108438089739-127.0.0.1:32850_solr-n_0000000002) [n:127.0.0.1:32850_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:32850_solr
[junit4] 2> 1073950 INFO (zkCallback-1540-thread-1-processing-n:127.0.0.1:32850_solr) [n:127.0.0.1:32850_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1073955 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1073955 DEBUG (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 1073956 INFO (zkCallback-1531-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 1073956 INFO (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41620_solr
[junit4] 2> 1073957 INFO (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.Overseer Overseer (id=73345108438089742-127.0.0.1:41620_solr-n_0000000003) starting
[junit4] 2> 1073957 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3d310d8f{/solr,null,UNAVAILABLE}
[junit4] 2> 1073957 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Stopped scavenging
[junit4] 2> 1073961 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 1073962 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 6
[junit4] 2> 1073962 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:41620_solr]
[junit4] 2> 1073962 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion -1
[junit4] 2> 1073962 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 6
[junit4] 2> 1073964 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1073964 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 6, lastZnodeVersion 6
[junit4] 2> 1073964 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1074965 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1075966 DEBUG (ScheduledTrigger-2607-thread-2) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1076966 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1077967 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1078958 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-22T02:57:37+05:30, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
[junit4] 2> 1078962 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 1078962 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 1078962 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.session Scavenging every 600000ms
[junit4] 2> 1078963 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@56900ad{/solr,null,AVAILABLE}
[junit4] 2> 1078963 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@e42ebf{HTTP/1.1,[http/1.1]}{127.0.0.1:50159}
[junit4] 2> 1078963 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.e.j.s.Server Started @1081408ms
[junit4] 2> 1078963 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50159}
[junit4] 2> 1078963 ERROR (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1078964 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 1078964 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1078964 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1078964 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-02-23T13:53:47.543Z
[junit4] 2> 1078967 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1
[junit4] 2> 1078975 INFO (zkConnectionManagerCallback-1556-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1078975 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 1078994 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:59445/solr
[junit4] 2> 1079025 INFO (zkConnectionManagerCallback-1560-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1079033 INFO (zkConnectionManagerCallback-1562-thread-1-processing-n:127.0.0.1:50159_solr) [n:127.0.0.1:50159_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 1079039 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1079040 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1079042 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50159_solr
[junit4] 2> 1079045 INFO (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1079045 INFO (zkCallback-1531-thread-3) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1079045 INFO (zkCallback-1531-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1079045 INFO (zkCallback-1531-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1079051 INFO (zkCallback-1561-thread-1-processing-n:127.0.0.1:50159_solr) [n:127.0.0.1:50159_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1079156 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50159.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1079166 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50159.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1079166 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50159.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@7f4734c5
[junit4] 2> 1079167 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [n:127.0.0.1:50159_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.autoscaling.TriggerIntegrationTest_24B4BD63E0209CAF-001/tempDir-001/node5/.
[junit4] 2> 1079967 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1080202 DEBUG (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: triggerScheduleDelaySeconds from: 1 to: 4
[junit4] 2> 1080968 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1081968 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1082968 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1083969 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1084969 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1085969 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1086969 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1087970 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1088205 DEBUG (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: triggerScheduleDelaySeconds from: 4 to: 1
[junit4] 2> 1088970 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1089970 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1090971 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1091971 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1092971 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1093972 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1094972 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1095972 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1096972 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1097973 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1098215 DEBUG (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers Changing value of autoscaling property: triggerCorePoolSize from: 4 to: 6
[junit4] 2> 1098973 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1099973 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1100974 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1101974 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1102975 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1103975 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1104975 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1105975 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1106976 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1107976 DEBUG (ScheduledTrigger-2607-thread-1) [n:127.0.0.1:41620_solr ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2
[junit4] 2> 1108222 INFO (TEST-TriggerIntegrationTest.testSetProperties-seed#[24B4BD63E0209CAF]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testSetProperties
[junit4] 2> 1108235 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[24B4BD63E0209CAF]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testNodeLostTrigger
[junit4] 2> 1108236 INFO (qtp730770475-8098) [n:127.0.0.1:41620_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 1108242 INFO (qtp730770475-8098) [n:127.0.0.1:41620_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=6
[junit4] 2> 1108243 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.ScheduledTriggers -- removing trigger: .auto_add_replicas
[junit4] 2> 1108244 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.a.TriggerIntegrationTest /autoscaling.json reset, new znode version 7
[junit4] 2> 1108245 DEBUG (zkCallback-1550-thread-1-processing-n:127.0.0.1:41620_solr) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 7
[junit4] 2> 1108245 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 7
[junit4] 2> 1108245 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 1108245 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_solr ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 1108245 INFO (TEST-TriggerIntegrationTest.testNodeLostTrigger-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1108245 DEBUG (OverseerAutoScalingTriggerThread-73345108438089742-127.0.0.1:41620_solr-n_0000000003) [n:127.0.0.1:41620_
[...truncated too long message...]
[junit4] 2> 1520008 ERROR (TEST-ShardRoutingTest.test-seed#[24B4BD63E0209CAF]) [ ] 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> 1520008 INFO (TEST-ShardRoutingTest.test-seed#[24B4BD63E0209CAF]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42625 42625
[junit4] 2> 1520185 INFO (Thread-2158) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:42625 42625
[junit4] 2> 1520186 WARN (Thread-2158) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/aliases.json
[junit4] 2> 9 /solr/security.json
[junit4] 2> 9 /solr/configs/conf1
[junit4] 2> 5 /solr/collections/collection1/terms/shard1
[junit4] 2> 5 /solr/collections/collection1/terms/shard2
[junit4] 2> 5 /solr/collections/collection1/terms/shard3
[junit4] 2> 5 /solr/collections/collection1/terms/shard4
[junit4] 2> 2 /solr/collections/control_collection/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/clusterprops.json
[junit4] 2> 11 /solr/clusterstate.json
[junit4] 2> 9 /solr/autoscaling.json
[junit4] 2> 8 /solr/collections/collection1/state.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 11 /solr/collections
[junit4] 2> 9 /solr/overseer/queue
[junit4] 2> 9 /solr/overseer/queue-work
[junit4] 2> 9 /solr/overseer/collection-queue-work
[junit4] 2> 8 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2>
[junit4] 2> 1520187 INFO (SUITE-ShardRoutingTest-seed#[24B4BD63E0209CAF]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> Feb 23, 2018 2:01:09 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> Feb 23, 2018 2:01:29 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardRoutingTest:
[junit4] 2> 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> Feb 23, 2018 2:01:29 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
[junit4] 2> Feb 23, 2018 2:01:32 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> SEVERE: There are still zombie threads that couldn't be terminated:
[junit4] 2> 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
[junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4] 2> at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] 2> at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=Memory)}, docValues:{foo_i=DocValuesFormat(name=Lucene70), _version_=DocValuesFormat(name=Lucene70)}, maxPointsInLeafNode=1275, maxMBSortInHeap=5.19073530171366, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@70192e62), locale=ar-SA, timezone=America/Pangnirtung
[junit4] 2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=4,threads=2,free=195209176,total=520093696
[junit4] 2> NOTE: All tests run in this JVM: [PluginInfoTest, TestPHPSerializedResponseWriter, BinaryUpdateRequestHandlerTest, TestPullReplicaErrorHandling, TestDistribStateManager, TestRebalanceLeaders, TestClusterProperties, TestCrossCoreJoin, TestHdfsBackupRestoreCore, TestCollectionsAPIViaSolrCloudCluster, TestFastOutputStream, OverseerCollectionConfigSetProcessorTest, TestHalfAndHalfDocValues, TestFreeTextSuggestions, DistributedTermsComponentTest, ShardSplitTest, TestUseDocValuesAsStored2, TestManagedSchemaThreadSafety, SuggestComponentContextFilterQueryTest, CdcrReplicationDistributedZkTest, TestConfig, TestTrackingShardHandlerFactory, OutputWriterTest, TestGroupingSearch, ChaosMonkeyNothingIsSafeTest, SecurityConfHandlerTest, TestCollationField, TestSegmentSorting, TestEmbeddedSolrServerSchemaAPI, TestSkipOverseerOperations, TestRestoreCore, TestMultiValuedNumericRangeQuery, TestManagedSynonymFilterFactory, ReplicaListTransformerTest, TestStandardQParsers, BlockDirectoryTest, DistribDocExpirationUpdateProcessorTest, DirectoryFactoryTest, TestInitParams, BaseCdcrDistributedZkTest, TestLargeCluster, TestSolrXml, TestStressLucene, TestMergePolicyConfig, TestDynamicLoading, TestRemoteStreaming, LeaderFailureAfterFreshStartTest, StressHdfsTest, TestQueryWrapperFilter, SharedFSAutoReplicaFailoverTest, TestTestInjection, DateRangeFieldTest, DeleteLastCustomShardedReplicaTest, TestOmitPositions, TestSchemalessBufferedUpdates, SimpleFacetsTest, TestDocumentBuilder, TestOrdValues, TriggerIntegrationTest, SolrSlf4jReporterTest, QueryResultKeyTest, TestDistributedSearch, HLLUtilTest, ZkShardTermsTest, TestLegacyFieldReuse, TestPseudoReturnFields, TestPhraseSuggestions, RulesTest, UUIDFieldTest, ActionThrottleTest, TestRandomFaceting, ShardRoutingTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardRoutingTest -Dtests.seed=24B4BD63E0209CAF -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=ar-SA -Dtests.timezone=America/Pangnirtung -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J0 | ShardRoutingTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.ShardRoutingTest:
[junit4] > 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] > at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at __randomizedtesting.SeedInfo.seed([24B4BD63E0209CAF]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=9777, name=qtp795916695-9777, state=TIMED_WAITING, group=TGRP-ShardRoutingTest]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
[junit4] > at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
[junit4] > at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
[junit4] > at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > at __randomizedtesting.SeedInfo.seed([24B4BD63E0209CAF]:0)
[junit4] Completed [465/778 (2!)] on J0 in 76.08s, 1 test, 2 errors <<< FAILURES!
[...truncated 51064 lines...]