You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2018/01/07 04:01:40 UTC
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk-9.0.1) - Build #
21230 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21230/
Java: 64bit/jdk-9.0.1 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.test_dv
Error Message:
java.lang.RuntimeException: Error from server at http://127.0.0.1:44045/solr/test_col: Failed synchronous update on shard StdNode: http://127.0.0.1:46491/solr/test_col_shard2_replica_n6/ update: org.apache.solr.client.solrj.request.UpdateRequest@5ad0ef98
Stack Trace:
java.util.concurrent.ExecutionException: java.lang.RuntimeException: Error from server at http://127.0.0.1:44045/solr/test_col: Failed synchronous update on shard StdNode: http://127.0.0.1:46491/solr/test_col_shard2_replica_n6/ update: org.apache.solr.client.solrj.request.UpdateRequest@5ad0ef98
at __randomizedtesting.SeedInfo.seed([460B24A18D8FF563:701F46E707D2CF72]:0)
at java.base/java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.base/java.util.concurrent.FutureTask.get(FutureTask.java:191)
at org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.checkField(TestStressCloudBlindAtomicUpdates.java:283)
at org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates.test_dv(TestStressCloudBlindAtomicUpdates.java:195)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Caused by: java.lang.RuntimeException: Error from server at http://127.0.0.1:44045/solr/test_col: Failed synchronous update on shard StdNode: http://127.0.0.1:46491/solr/test_col_shard2_replica_n6/ update: org.apache.solr.client.solrj.request.UpdateRequest@5ad0ef98
at org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates$Worker.run(TestStressCloudBlindAtomicUpdates.java:411)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:514)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:188)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
... 1 more
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:44045/solr/test_col: Failed synchronous update on shard StdNode: http://127.0.0.1:46491/solr/test_col_shard2_replica_n6/ update: org.apache.solr.client.solrj.request.UpdateRequest@5ad0ef98
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:643)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
at org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates$Worker.doRandomAtomicUpdate(TestStressCloudBlindAtomicUpdates.java:370)
at org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates$Worker.run(TestStressCloudBlindAtomicUpdates.java:399)
... 6 more
Build Log:
[...truncated 13551 lines...]
[junit4] Suite: org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates
[junit4] 2> 2887113 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/init-core-data-001
[junit4] 2> 2887113 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2887114 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="SSL overhead seems to cause OutOfMemory when stress testing")
[junit4] 2> 2887114 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001
[junit4] 2> 2887114 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2887115 INFO (Thread-5276) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2887115 INFO (Thread-5276) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2887116 ERROR (Thread-5276) [ ] 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> 2887215 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:33319
[junit4] 2> 2887216 INFO (zkConnectionManagerCallback-5558-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887218 INFO (jetty-launcher-5555-thread-3) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2887218 INFO (jetty-launcher-5555-thread-4) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2887218 INFO (jetty-launcher-5555-thread-1) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2887218 INFO (jetty-launcher-5555-thread-2) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 2887218 INFO (jetty-launcher-5555-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7680e690{/solr,null,AVAILABLE}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@39255560{/solr,null,AVAILABLE}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5424fe2e{/solr,null,AVAILABLE}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7dc26598{HTTP/1.1,[http/1.1]}{127.0.0.1:۴۶۴۹۱}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.e.j.s.Server Started @۲۸۸۸۶۱۹ms
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46491}
[junit4] 2> 2887219 ERROR (jetty-launcher-5555-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-07T03:39:04.441534Z
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@c46979d{/solr,null,AVAILABLE}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@23753ec{HTTP/1.1,[http/1.1]}{127.0.0.1:۴۱۲۶۱}
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-1) [ ] o.e.j.s.Server Started @۲۸۸۸۶۲۰ms
[junit4] 2> 2887219 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41261}
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@223a02a1{HTTP/1.1,[http/1.1]}{127.0.0.1:۳۲۸۴۳}
[junit4] 2> 2887220 ERROR (jetty-launcher-5555-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e96bf08{HTTP/1.1,[http/1.1]}{127.0.0.1:۴۴۰۴۵}
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-2) [ ] o.e.j.s.Server Started @۲۸۸۸۶۲۱ms
[junit4] 2> 2887220 INFO (zkConnectionManagerCallback-5560-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44045}
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-4) [ ] o.e.j.s.Server Started @۲۸۸۸۶۲۰ms
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=32843}
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2887220 ERROR (jetty-launcher-5555-thread-4) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2887220 ERROR (jetty-launcher-5555-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.0.0
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-07T03:39:04.443390Z
[junit4] 2> 2887221 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-07T03:39:04.443426Z
[junit4] 2> 2887220 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-01-07T03:39:04.442967Z
[junit4] 2> 2887222 INFO (zkConnectionManagerCallback-5565-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887222 INFO (zkConnectionManagerCallback-5566-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887222 INFO (zkConnectionManagerCallback-5564-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887222 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2887222 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2887222 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2887225 INFO (jetty-launcher-5555-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33319/solr
[junit4] 2> 2887225 INFO (jetty-launcher-5555-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33319/solr
[junit4] 2> 2887225 INFO (zkConnectionManagerCallback-5570-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887226 INFO (zkConnectionManagerCallback-5575-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887226 INFO (jetty-launcher-5555-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33319/solr
[junit4] 2> 2887227 INFO (zkConnectionManagerCallback-5578-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887227 INFO (zkConnectionManagerCallback-5580-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887227 INFO (zkConnectionManagerCallback-5582-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887228 INFO (zkConnectionManagerCallback-5584-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887229 INFO (jetty-launcher-5555-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:33319/solr
[junit4] 2> 2887237 INFO (zkConnectionManagerCallback-5589-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887255 INFO (zkConnectionManagerCallback-5593-thread-1-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887275 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2887275 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:44045_solr
[junit4] 2> 2887277 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.c.Overseer Overseer (id=99306461222469644-127.0.0.1:44045_solr-n_0000000000) starting
[junit4] 2> 2887304 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2887306 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44045_solr
[junit4] 2> 2887306 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46491_solr
[junit4] 2> 2887306 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2887308 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2887308 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2887309 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2887313 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32843_solr
[junit4] 2> 2887318 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2887319 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2887319 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2887319 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2887320 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41261_solr
[junit4] 2> 2887324 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2887324 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2887324 INFO (zkCallback-5592-thread-1-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2887324 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2887328 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 2887357 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44045.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887365 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46491.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887367 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44045.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887367 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44045.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887368 INFO (jetty-launcher-5555-thread-2) [n:127.0.0.1:44045_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node2/.
[junit4] 2> 2887372 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46491.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887372 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46491.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887373 INFO (jetty-launcher-5555-thread-3) [n:127.0.0.1:46491_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node3/.
[junit4] 2> 2887400 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32843.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887400 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41261.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887405 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32843.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887405 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32843.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887405 INFO (jetty-launcher-5555-thread-4) [n:127.0.0.1:32843_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node4/.
[junit4] 2> 2887408 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41261.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887408 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41261.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2887409 INFO (jetty-launcher-5555-thread-1) [n:127.0.0.1:41261_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node1/.
[junit4] 2> 2887481 INFO (zkConnectionManagerCallback-5600-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887483 INFO (zkConnectionManagerCallback-5604-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887483 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 2887484 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:33319/solr ready
[junit4] 2> 2887621 INFO (qtp2053954055-25861) [n:127.0.0.1:32843_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&name=test_col&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2887621 INFO (OverseerThreadFactory-10412-thread-1-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.CreateCollectionCmd Create collection test_col
[junit4] 2> 2887724 INFO (OverseerStateUpdate-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test_col",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"test_col_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41261/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887725 INFO (OverseerStateUpdate-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test_col",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"test_col_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:32843/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887726 INFO (OverseerStateUpdate-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test_col",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"test_col_shard2_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44045/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887726 INFO (OverseerStateUpdate-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"test_col",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"test_col_shard2_replica_n6",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46491/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887929 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node5&name=test_col_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin
[junit4] 2> 2887929 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node8&name=test_col_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin
[junit4] 2> 2887929 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2887929 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2887929 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node3&name=test_col_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin
[junit4] 2> 2887929 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node7&name=test_col_shard2_replica_n4&action=CREATE&numShards=2&shard=shard2&wt=javabin
[junit4] 2> 2887929 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2887929 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2888031 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888031 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888032 INFO (zkCallback-5592-thread-1-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888032 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888031 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888032 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888031 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888032 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2888935 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2888936 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2888941 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2888941 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.0.0
[junit4] 2> 2888943 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.s.IndexSchema [test_col_shard2_replica_n4] Schema name=minimal-atomic-stress
[junit4] 2> 2888943 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.s.IndexSchema [test_col_shard2_replica_n6] Schema name=minimal-atomic-stress
[junit4] 2> 2888944 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.s.IndexSchema Loaded schema minimal-atomic-stress/1.6 with uniqueid field id
[junit4] 2> 2888944 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.CoreContainer Creating SolrCore 'test_col_shard2_replica_n4' using configuration from collection test_col, trusted=true
[junit4] 2> 2888944 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.s.IndexSchema Loaded schema minimal-atomic-stress/1.6 with uniqueid field id
[junit4] 2> 2888944 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.CoreContainer Creating SolrCore 'test_col_shard2_replica_n6' using configuration from collection test_col, trusted=true
[junit4] 2> 2888956 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44045.solr.core.test_col.shard2.replica_n4' (registry 'solr.core.test_col.shard2.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2888956 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46491.solr.core.test_col.shard2.replica_n6' (registry 'solr.core.test_col.shard2.replica_n6') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2888956 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2888956 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2888956 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SolrCore [[test_col_shard2_replica_n4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node2/test_col_shard2_replica_n4], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node2/./test_col_shard2_replica_n4/data/]
[junit4] 2> 2888956 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.SolrCore [[test_col_shard2_replica_n6] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node3/test_col_shard2_replica_n6], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node3/./test_col_shard2_replica_n6/data/]
[junit4] 2> 2888958 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.s.IndexSchema [test_col_shard1_replica_n2] Schema name=minimal-atomic-stress
[junit4] 2> 2888958 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=4.013671875, floorSegmentMB=1.4609375, forceMergeDeletesPctAllowed=13.362969378947474, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.30150902318007927
[junit4] 2> 2888958 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=4.013671875, floorSegmentMB=1.4609375, forceMergeDeletesPctAllowed=13.362969378947474, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.30150902318007927
[junit4] 2> 2888958 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.s.IndexSchema [test_col_shard1_replica_n1] Schema name=minimal-atomic-stress
[junit4] 2> 2888959 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.s.IndexSchema Loaded schema minimal-atomic-stress/1.6 with uniqueid field id
[junit4] 2> 2888959 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.CoreContainer Creating SolrCore 'test_col_shard1_replica_n2' using configuration from collection test_col, trusted=true
[junit4] 2> 2888959 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_32843.solr.core.test_col.shard1.replica_n2' (registry 'solr.core.test_col.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2888959 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2888959 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.SolrCore [[test_col_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node4/test_col_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node4/./test_col_shard1_replica_n2/data/]
[junit4] 2> 2888959 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema minimal-atomic-stress/1.6 with uniqueid field id
[junit4] 2> 2888959 WARN (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2888959 WARN (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2888959 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'test_col_shard1_replica_n1' using configuration from collection test_col, trusted=true
[junit4] 2> 2888960 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41261.solr.core.test_col.shard1.replica_n1' (registry 'solr.core.test_col.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@552d4c76
[junit4] 2> 2888960 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 2888960 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SolrCore [[test_col_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node1/test_col_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001/tempDir-001/node1/./test_col_shard1_replica_n1/data/]
[junit4] 2> 2888960 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=4.013671875, floorSegmentMB=1.4609375, forceMergeDeletesPctAllowed=13.362969378947474, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.30150902318007927
[junit4] 2> 2888962 WARN (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2888962 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=41, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=4.013671875, floorSegmentMB=1.4609375, forceMergeDeletesPctAllowed=13.362969378947474, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.30150902318007927
[junit4] 2> 2888963 WARN (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
[junit4] 2> 2888987 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2888987 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2888988 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2888988 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2888989 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=0.404296875, floorSegmentMB=0.5234375, forceMergeDeletesPctAllowed=2.3597898778172564, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2888989 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.s.SolrIndexSearcher Opening [Searcher@67114a2[test_col_shard2_replica_n4] main]
[junit4] 2> 2888990 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2888990 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2888991 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2888991 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588903381526642688
[junit4] 2> 2888993 INFO (searcherExecutor-10421-thread-1-processing-n:127.0.0.1:44045_solr x:test_col_shard2_replica_n4 s:shard2 c:test_col r:core_node7) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SolrCore [test_col_shard2_replica_n4] Registered new searcher Searcher@67114a2[test_col_shard2_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2888994 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2888994 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2889012 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2889012 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2889012 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2889013 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2889013 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2889014 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2889014 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2889014 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=0.404296875, floorSegmentMB=0.5234375, forceMergeDeletesPctAllowed=2.3597898778172564, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2889015 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.s.SolrIndexSearcher Opening [Searcher@2972abdb[test_col_shard2_replica_n6] main]
[junit4] 2> 2889015 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889015 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889016 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2889016 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2889016 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2889016 INFO (searcherExecutor-10422-thread-1-processing-n:127.0.0.1:46491_solr x:test_col_shard2_replica_n6 s:shard2 c:test_col r:core_node8) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.SolrCore [test_col_shard2_replica_n6] Registered new searcher Searcher@2972abdb[test_col_shard2_replica_n6] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2889016 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588903381552857088
[junit4] 2> 2889017 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2889017 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2889017 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=0.404296875, floorSegmentMB=0.5234375, forceMergeDeletesPctAllowed=2.3597898778172564, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2889017 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@77a48e42[test_col_shard1_replica_n2] main]
[junit4] 2> 2889017 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=0.404296875, floorSegmentMB=0.5234375, forceMergeDeletesPctAllowed=2.3597898778172564, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 2889017 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b1839c9[test_col_shard1_replica_n1] main]
[junit4] 2> 2889018 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889018 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889018 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889018 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 2889018 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2889018 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2889019 INFO (searcherExecutor-10423-thread-1-processing-n:127.0.0.1:32843_solr x:test_col_shard1_replica_n2 s:shard1 c:test_col r:core_node5) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.SolrCore [test_col_shard1_replica_n2] Registered new searcher Searcher@77a48e42[test_col_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2889019 INFO (searcherExecutor-10424-thread-1-processing-n:127.0.0.1:41261_solr x:test_col_shard1_replica_n1 s:shard1 c:test_col r:core_node3) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SolrCore [test_col_shard1_replica_n1] Registered new searcher Searcher@3b1839c9[test_col_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2889019 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588903381556002816
[junit4] 2> 2889019 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1588903381556002816
[junit4] 2> 2889022 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2889022 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2889022 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41261/solr/test_col_shard1_replica_n1/
[junit4] 2> 2889022 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=test_col_shard1_replica_n1 url=http://127.0.0.1:41261/solr START replicas=[http://127.0.0.1:32843/solr/test_col_shard1_replica_n2/] nUpdates=100
[junit4] 2> 2889023 INFO (qtp2053954055-25850) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.c.S.Request [test_col_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889123 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5592-thread-3-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889123 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889323 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=test_col_shard1_replica_n1 url=http://127.0.0.1:41261/solr DONE. We have no versions. sync failed.
[junit4] 2> 2889323 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2889323 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2889323 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2889325 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41261/solr/test_col_shard1_replica_n1/ shard1
[junit4] 2> 2889426 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889426 INFO (zkCallback-5592-thread-3-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889475 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2889476 INFO (qtp1282844067-25863) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node3&name=test_col_shard1_replica_n1&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=1546
[junit4] 2> 2889512 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2889512 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2889512 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/
[junit4] 2> 2889513 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=test_col_shard2_replica_n4 url=http://127.0.0.1:44045/solr START replicas=[http://127.0.0.1:46491/solr/test_col_shard2_replica_n6/] nUpdates=100
[junit4] 2> 2889513 INFO (qtp1604276417-25860) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.S.Request [test_col_shard2_replica_n6] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889577 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5592-thread-3-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889577 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889813 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.PeerSync PeerSync: core=test_col_shard2_replica_n4 url=http://127.0.0.1:44045/solr DONE. We have no versions. sync failed.
[junit4] 2> 2889813 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2889813 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2889813 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 2889814 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/ shard2
[junit4] 2> 2889915 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889915 INFO (zkCallback-5592-thread-3-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2889965 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2890013 INFO (qtp987949488-25869) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node7&name=test_col_shard2_replica_n4&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2084
[junit4] 2> 2890020 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node8&name=test_col_shard2_replica_n6&action=CREATE&numShards=2&shard=shard2&wt=javabin} status=0 QTime=2091
[junit4] 2> 2890023 INFO (qtp2053954055-25844) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&newCollection=true&collection=test_col&version=2&replicaType=NRT&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&coreNodeName=core_node5&name=test_col_shard1_replica_n2&action=CREATE&numShards=2&shard=shard1&wt=javabin} status=0 QTime=2094
[junit4] 2> 2890024 INFO (qtp2053954055-25861) [n:127.0.0.1:32843_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> 2890123 INFO (zkCallback-5592-thread-3-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5579-thread-1-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5592-thread-2-processing-n:127.0.0.1:44045_solr) [n:127.0.0.1:44045_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5581-thread-2-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5579-thread-2-processing-n:127.0.0.1:46491_solr) [n:127.0.0.1:46491_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5581-thread-1-processing-n:127.0.0.1:41261_solr) [n:127.0.0.1:41261_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5583-thread-2-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2890123 INFO (zkCallback-5583-thread-1-processing-n:127.0.0.1:32843_solr) [n:127.0.0.1:32843_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/test_col/state.json] for collection [test_col] has occurred - updating... (live nodes size: [4])
[junit4] 2> 2891024 INFO (qtp2053954055-25861) [n:127.0.0.1:32843_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&property.schema=schema-minimal-atomic-stress.xml&property.config=solrconfig-tlog.xml&collection.configName=org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set&name=test_col&nrtReplicas=2&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3403
[junit4] 2> 2891024 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: test_col failOnTimeout:true timeout (sec):330
[junit4] 1> -
[junit4] 1> replica:core_node3 rstate:active live:true
[junit4] 1> replica:core_node5 rstate:active live:true
[junit4] 1> replica:core_node7 rstate:active live:true
[junit4] 1> replica:core_node8 rstate:active live:true
[junit4] 1> no one is recoverying
[junit4] 2> 2891025 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: test_col
[junit4] 2> 2891028 INFO (qtp1282844067-25870) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.c.S.Request [test_col_shard1_replica_n1] webapp=/solr path=/schema/fieldtypes/long params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2891043 INFO (TEST-TestStressCloudBlindAtomicUpdates.test_dv_idx-seed#[460B24A18D8FF563]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test_dv_idx
[junit4] 2> 2891047 INFO (qtp2053954055-25867) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1588903383680417792&distrib.from=http://127.0.0.1:41261/solr/test_col_shard1_replica_n1/&wt=javabin&version=2}{deleteByQuery=*:* (-1588903383680417792)} 0 0
[junit4] 2> 2891048 INFO (qtp1282844067-25848) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&wt=javabin&version=2}{deleteByQuery=*:* (-1588903383680417792)} 0 2
[junit4] 2> 2891048 INFO (qtp1604276417-25840) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1588903383679369216&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&wt=javabin&version=2}{deleteByQuery=*:* (-1588903383679369216)} 0 2
[junit4] 2> 2891048 INFO (qtp987949488-25874) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1588903383679369216)} 0 4
[junit4] 2> 2891049 INFO (qtp1282844067-25847) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588903383684612096,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2891049 WARN (qtp1282844067-25847) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
[junit4] 2> 2891049 INFO (qtp2053954055-25854) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588903383684612096,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2891049 WARN (qtp2053954055-25854) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
[junit4] 2> 2891050 INFO (qtp1604276417-25842) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588903383684612096,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2891050 WARN (qtp1604276417-25842) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
[junit4] 2> 2891050 INFO (qtp2053954055-25854) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2891049 INFO (qtp987949488-25858) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1588903383684612096,optimize=true,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2891050 WARN (qtp987949488-25858) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.DirectUpdateHandler2 Starting optimize... Reading and rewriting the entire index! Use with care.
[junit4] 2> 2891050 INFO (qtp2053954055-25854) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2891049 INFO (qtp1282844067-25847) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2891050 INFO (qtp987949488-25858) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2891051 INFO (qtp1282844067-25847) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2891051 INFO (qtp987949488-25858) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2891050 INFO (qtp1604276417-25842) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2891051 INFO (qtp987949488-25858) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica_n4] webapp=/solr path=/update params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=} 0 1
[junit4] 2> 2891051 INFO (qtp1604276417-25842) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2891051 INFO (qtp1604276417-25842) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica_n6] webapp=/solr path=/update params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=} 0 1
[junit4] 2> 2891051 INFO (qtp1282844067-25847) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=} 0 2
[junit4] 2> 2891053 INFO (qtp2053954055-25854) [n:127.0.0.1:32843_solr c:test_col s:shard1 r:core_node5 x:test_col_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&optimize=true&maxSegments=1&waitSearcher=true&openSearcher=true&distrib.from=http://127.0.0.1:44045/solr/test_col_shard2_replica_n4/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{optimize=} 0 3
[junit4] 2> 2891053 INFO (qtp987949488-25845) [n:127.0.0.1:44045_solr c:test_col s:shard2 r:core_node7 x:test_col_shard2_replica_n4] o.a.s.u.p.LogUpdateProcessorFactory [test_col_shard2_replica_n4] webapp=/solr path=/update params={_stateVer_=test_col:7&optimize=true&maxSegments=1&waitSearcher=true&wt=javabin&version=2}{optimize=} 0 4
[junit4] 2> 2891054 INFO (qtp1604276417-25855) [n:127.0.0.1:46491_solr c:test_col s:shard2 r:core_node8 x:test_col_shard2_replica_n6] o.a.s.c.S.Request [test_col_shard2_replica_n6] webap
[...truncated too long message...]
7 INFO (coreCloseExecutor-10443-thread-1) [n:127.0.0.1:41261_solr c:test_col s:shard1 r:core_node3 x:test_col_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6dc56ff6 commitCommandVersion:0
[junit4] 2> 2914443 INFO (jetty-closer-5556-thread-1) [ ] o.a.s.c.Overseer Overseer (id=99306461222469644-127.0.0.1:44045_solr-n_0000000000) closing
[junit4] 2> 2914443 INFO (OverseerStateUpdate-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:44045_solr
[junit4] 2> 2914445 WARN (OverseerAutoScalingTriggerThread-99306461222469644-127.0.0.1:44045_solr-n_0000000000) [n:127.0.0.1:44045_solr ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2914445 INFO (jetty-closer-5556-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5424fe2e{/solr,null,UNAVAILABLE}
[junit4] 2> 2914445 INFO (jetty-closer-5556-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7680e690{/solr,null,UNAVAILABLE}
[junit4] 2> 2914448 INFO (jetty-closer-5556-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@39255560{/solr,null,UNAVAILABLE}
[junit4] 2> 2914455 INFO (jetty-closer-5556-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@c46979d{/solr,null,UNAVAILABLE}
[junit4] 2> 2914456 ERROR (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 2914456 INFO (SUITE-TestStressCloudBlindAtomicUpdates-seed#[460B24A18D8FF563]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33319 33319
[junit4] 2> 2919569 INFO (Thread-5276) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:33319 33319
[junit4] 2> 2919569 WARN (Thread-5276) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/aliases.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 4 /solr/configs/org.apache.solr.cloud.TestStressCloudBlindAtomicUpdates_config-set
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 36 /solr/collections/test_col/state.json
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 2 /solr/overseer_elect/election/99306461222469644-127.0.0.1:44045_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/live_nodes
[junit4] 2> 5 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.TestStressCloudBlindAtomicUpdates_460B24A18D8FF563-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {id=PostingsFormat(name=LuceneVarGapFixedInterval)}, docValues:{_version_=DocValuesFormat(name=Lucene70), long_dv_idx=DocValuesFormat(name=Memory), long_dv_stored=DocValuesFormat(name=Direct), id=DocValuesFormat(name=Memory), long_dv=DocValuesFormat(name=Direct), long_dv_stored_idx=DocValuesFormat(name=Memory)}, maxPointsInLeafNode=1358, maxMBSortInHeap=7.791583938132119, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@45a3166), locale=lrc, timezone=Indian/Maldives
[junit4] 2> NOTE: Linux 4.10.0-40-generic amd64/Oracle Corporation 9.0.1 (64-bit)/cpus=8,threads=1,free=157818176,total=518979584
[junit4] 2> NOTE: All tests run in this JVM: [TestIndexSearcher, TestQuerySenderListener, TestSolrCoreProperties, TestSearchPerf, TestSearcherReuse, HdfsLockFactoryTest, TestRandomFlRTGCloud, TestBulkSchemaAPI, TestCustomStream, SpatialRPTFieldTypeTest, CdcrReplicationHandlerTest, MoveReplicaHDFSFailoverTest, TestValueSourceCache, TestReload, TestSolrCloudWithKerberosAlt, TestTolerantUpdateProcessorCloud, TestGroupingSearch, TestSolr4Spatial2, TestBackupRepositoryFactory, TestDocBasedVersionConstraints, SolrTestCaseJ4Test, ManagedSchemaRoundRobinCloudTest, SystemInfoHandlerTest, TestExactSharedStatsCache, BlockJoinFacetDistribTest, TestMissingGroups, TestAddFieldRealTimeGet, RegexBytesRefFilterTest, TestElisionMultitermQuery, UnloadDistributedZkTest, RequiredFieldsTest, TestCollectionAPI, TestCloudRecovery, TestUseDocValuesAsStored, TestPushWriter, TestSSLRandomization, UniqFieldsUpdateProcessorFactoryTest, VersionInfoTest, TestTolerantSearch, DateRangeFieldTest, StatsComponentTest, TestQueryTypes, DistributedExpandComponentTest, TimeZoneUtilsTest, CollectionReloadTest, HdfsRecoverLeaseTest, HttpPartitionTest, TestMacros, FileBasedSpellCheckerTest, BasicDistributedZk2Test, TestTestInjection, SystemLogListenerTest, TestDynamicFieldResource, SecurityConfHandlerTest, ExplicitHLLTest, TestFreeTextSuggestions, TestCoreAdminApis, TestSolrDeletionPolicy2, CoreAdminHandlerTest, V2ApiIntegrationTest, TestManagedSchema, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestLMDirichletSimilarityFactory, ReturnFieldsTest, AlternateDirectoryTest, TestNumericTerms32, AtomicUpdatesTest, NodeAddedTriggerTest, TestJsonFacetRefinement, TestConfigSetsAPIExclusivity, TestSolrConfigHandler, IndexBasedSpellCheckerTest, TestStandardQParsers, TestClusterStateProvider, SolrGraphiteReporterTest, TestNodeAddedTrigger, PluginInfoTest, TestSolrConfigHandlerCloud, DistanceFunctionTest, ConfigureRecoveryStrategyTest, TlogReplayBufferedWhileIndexingTest, ReplaceNodeTest, TestSchemaResource, ExitableDirectoryReaderTest, FieldAnalysisRequestHandlerTest, TestDeleteCollectionOnDownNodes, TestInitQParser, TestExecutePlanAction, TestFieldCacheVsDocValues, HighlighterTest, TestQueryWrapperFilter, TestUnifiedSolrHighlighter, TestSolrCoreSnapshots, TestEmbeddedSolrServerConstructors, TestAuthenticationFramework, CustomCollectionTest, LeaderFailureAfterFreshStartTest, TestDistributedGrouping, CloudMLTQParserTest, TestCloudJSONFacetJoinDomain, SuggestComponentContextFilterQueryTest, FullSolrCloudDistribCmdsTest, FieldMutatingUpdateProcessorTest, OverriddenZkACLAndCredentialsProvidersTest, TestManagedResource, RecoveryZkTest, UUIDFieldTest, PeerSyncReplicationTest, ResponseHeaderTest, TestCoreContainer, ImplicitSnitchTest, TestSerializedLuceneMatchVersion, OverseerRolesTest, TestExpandComponent, AutoScalingHandlerTest, TestLockTree, TestRealTimeGet, TestHdfsBackupRestoreCore, TestFilteredDocIdSet, TestSizeLimitedDistributedMap, SolrCoreCheckLockOnStartupTest, CollectionsAPIAsyncDistributedZkTest, TestHashPartitioner, IndexSchemaTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, LeaderElectionTest, TestFaceting, TestRecovery, DistributedSpellCheckComponentTest, TestStressReorder, TestRangeQuery, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, ShowFileRequestHandlerTest, SimplePostToolTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SpellCheckCollatorTest, TestFoldingMultitermQuery, SuggesterTSTTest, SuggesterTest, TestTrie, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, TestWordDelimiterFilterFactory, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, DocValuesMultiTest, TestSolrDeletionPolicy1, SolrInfoBeanTest, XsltUpdateRequestHandlerTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestWriterPerf, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, TestOmitPositions, TermsComponentTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, TermVectorComponentTest, MoreLikeThisHandlerTest, FastVectorHighlighterTest, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, TestJmxIntegration, TestCollationField, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, JsonLoaderTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, SearchHandlerTest, TestLFUCache, HighlighterConfigTest, SOLR749Test, TestQuerySenderNoQuery, CopyFieldTest, BadComponentTest, MultiTermTest, TestDocSet, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, SpellPossibilityIteratorTest, TestCharFilters, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, TestFastWriter, ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, AssignTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, ConcurrentDeleteAndCreateCollectionTest, ConfigSetsAPITest, CreateCollectionCleanupTest, DeleteNodeTest, DeleteStatusTest, DistributedQueueTest, NodeMutatorTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerCollectionConfigSetProcessorTest, RecoveryAfterSoftCommitTest, ReplicationFactorTest, RestartWhileUpdatingTest, RollingRestartTest, SSLMigrationTest, SaslZkACLProviderTest, ShardSplitTest, SharedFSAutoReplicaFailoverTest, SimpleCollectionCreateDeleteTest, SolrCLIZkUtilsTest, SolrXmlInZkTest, TestCloudInspectUtil, TestCloudPseudoReturnFields, TestConfigSetsAPI, TestExclusionRuleCollectionAccess, TestLeaderElectionZkExpiry, TestMiniSolrCloudClusterSSL, TestPrepRecovery, TestRandomRequestDistribution, TestReplicaProperties, TestSegmentSorting, TestShortCircuitedRequests, TestSolrCloudWithDelegationTokens, TestStressCloudBlindAtomicUpdates]
[junit4] Completed [558/766 (1!)] on J2 in 32.47s, 5 tests, 1 error <<< FAILURES!
[...truncated 41536 lines...]
[JENKINS] Lucene-Solr-master-Linux (32bit/jdk1.8.0_144) - Build #
21231 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/21231/
Java: 32bit/jdk1.8.0_144 -client -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.sim.TestLargeCluster.testNodeLost
Error Message:
should be at least 1 IGNORED events
Stack Trace:
java.lang.AssertionError: should be at least 1 IGNORED events
at __randomizedtesting.SeedInfo.seed([53FF2FBC4B6F58FB:ECEAE142C8853D7D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.autoscaling.sim.TestLargeCluster.doTestNodeLost(TestLargeCluster.java:423)
at org.apache.solr.cloud.autoscaling.sim.TestLargeCluster.testNodeLost(TestLargeCluster.java:307)
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 13589 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestLargeCluster
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestLargeCluster_53FF2FBC4B6F58FB-001/init-core-data-001
[junit4] 2> 3083517 WARN (SUITE-TestLargeCluster-seed#[53FF2FBC4B6F58FB]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=8 numCloses=8
[junit4] 2> 3083517 INFO (SUITE-TestLargeCluster-seed#[53FF2FBC4B6F58FB]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 3083519 INFO (SUITE-TestLargeCluster-seed#[53FF2FBC4B6F58FB]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 3083519 INFO (SUITE-TestLargeCluster-seed#[53FF2FBC4B6F58FB]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 3083520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3083520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 0
[junit4] 2> 3083520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10006_solr, 127.0.0.1:10010_solr, 127.0.0.1:10005_solr, 127.0.0.1:10009_solr, 127.0.0.1:10008_solr, 127.0.0.1:10012_solr, 127.0.0.1:10007_solr, 127.0.0.1:10011_solr]
[junit4] 2> 3083520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion -1
[junit4] 2> 3083520 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 0
[junit4] 2> 3083521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3083521 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 0, lastZnodeVersion 0
[junit4] 2> 3083521 DEBUG (ScheduledTrigger-10352-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 13
[junit4] 2> 3083538 INFO (TEST-TestLargeCluster.testBasic-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBasic
[junit4] 2> 3083539 DEBUG (TEST-TestLargeCluster.testBasic-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 3083539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 3083539 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeLost markers
[junit4] 2> 3083540 INFO (TEST-TestLargeCluster.testBasic-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimCloudManager === Restarting OverseerTriggerThread and clearing object cache...
[junit4] 2> 3083540 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3083541 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Interrupted
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireInterruptibly(AbstractQueuedSynchronizer.java:1220)
[junit4] 2> at java.util.concurrent.locks.ReentrantLock.lockInterruptibly(ReentrantLock.java:335)
[junit4] 2> at org.apache.solr.cloud.autoscaling.OverseerTriggerThread.run(OverseerTriggerThread.java:154)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2> 3083541 DEBUG (TEST-TestLargeCluster.testBasic-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .autoAddReplicas trigger
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10082_solr, 127.0.0.1:10018_solr, 127.0.0.1:10049_solr, 127.0.0.1:10104_solr, 127.0.0.1:10020_solr, 127.0.0.1:10065_solr, 127.0.0.1:10021_solr, 127.0.0.1:10005_solr, 127.0.0.1:10066_solr, 127.0.0.1:10035_solr, 127.0.0.1:10051_solr, 127.0.0.1:10019_solr, 127.0.0.1:10096_solr, 127.0.0.1:10022_solr, 127.0.0.1:10033_solr, 127.0.0.1:10017_solr, 127.0.0.1:10047_solr, 127.0.0.1:10102_solr, 127.0.0.1:10095_solr, 127.0.0.1:10081_solr, 127.0.0.1:10084_solr, 127.0.0.1:10036_solr, 127.0.0.1:10052_solr, 127.0.0.1:10006_solr, 127.0.0.1:10079_solr, 127.0.0.1:10098_solr, 127.0.0.1:10054_solr, 127.0.0.1:10099_solr, 127.0.0.1:10101_solr, 127.0.0.1:10071_solr, 127.0.0.1:10023_solr, 127.0.0.1:10076_solr, 127.0.0.1:10007_solr, 127.0.0.1:10055_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10070_solr, 127.0.0.1:10077_solr, 127.0.0.1:10038_solr, 127.0.0.1:10032_solr, 127.0.0.1:10093_solr, 127.0.0.1:10061_solr, 127.0.0.1:10067_solr, 127.0.0.1:10086_solr, 127.0.0.1:10089_solr, 127.0.0.1:10045_solr, 127.0.0.1:10042_solr, 127.0.0.1:10029_solr, 127.0.0.1:10083_solr, 127.0.0.1:10080_solr, 127.0.0.1:10048_solr, 127.0.0.1:10064_solr, 127.0.0.1:10043_solr, 127.0.0.1:10057_solr, 127.0.0.1:10074_solr, 127.0.0.1:10026_solr, 127.0.0.1:10012_solr, 127.0.0.1:10060_solr, 127.0.0.1:10073_solr, 127.0.0.1:10058_solr, 127.0.0.1:10013_solr, 127.0.0.1:10090_solr, 127.0.0.1:10088_solr, 127.0.0.1:10027_solr, 127.0.0.1:10039_solr, 127.0.0.1:10025_solr, 127.0.0.1:10044_solr, 127.0.0.1:10028_solr, 127.0.0.1:10092_solr, 127.0.0.1:10041_solr, 127.0.0.1:10087_solr, 127.0.0.1:10009_solr, 127.0.0.1:10030_solr, 127.0.0.1:10014_solr, 127.0.0.1:10011_solr, 127.0.0.1:10040_solr, 127.0.0.1:10085_solr, 127.0.0.1:10046_solr, 127.0.0.1:10068_solr, 127.0.0.1:10063_solr, 127.0.0.1:10015_solr, 127.0.0.1:10069_solr, 127.0.0.1:10062_solr, 127.0.0.1:10008_solr, 127.0.0.1:10024_solr, 127.0.0.1:10050_solr, 127.0.0.1:10075_solr, 127.0.0.1:10078_solr, 127.0.0.1:10097_solr, 127.0.0.1:10031_solr, 127.0.0.1:10034_solr, 127.0.0.1:10091_solr, 127.0.0.1:10094_solr, 127.0.0.1:10100_solr, 127.0.0.1:10037_solr, 127.0.0.1:10053_solr, 127.0.0.1:10059_solr, 127.0.0.1:10103_solr, 127.0.0.1:10056_solr, 127.0.0.1:10072_solr]
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion -1
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 3083542 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3083543 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 3083543 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083563 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083585 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083605 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083626 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083646 DEBUG (simCloudManagerPool-10354-thread-1) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3083646 DEBUG (simCloudManagerPool-10354-thread-1) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 3
[junit4] 2> 3083647 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083647 DEBUG (simCloudManagerPool-10354-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10082_solr, 127.0.0.1:10018_solr, 127.0.0.1:10049_solr, 127.0.0.1:10104_solr, 127.0.0.1:10020_solr, 127.0.0.1:10065_solr, 127.0.0.1:10021_solr, 127.0.0.1:10005_solr, 127.0.0.1:10066_solr, 127.0.0.1:10035_solr, 127.0.0.1:10051_solr, 127.0.0.1:10019_solr, 127.0.0.1:10096_solr, 127.0.0.1:10022_solr, 127.0.0.1:10033_solr, 127.0.0.1:10017_solr, 127.0.0.1:10047_solr, 127.0.0.1:10102_solr, 127.0.0.1:10095_solr, 127.0.0.1:10081_solr, 127.0.0.1:10084_solr, 127.0.0.1:10036_solr, 127.0.0.1:10052_solr, 127.0.0.1:10006_solr, 127.0.0.1:10079_solr, 127.0.0.1:10098_solr, 127.0.0.1:10054_solr, 127.0.0.1:10099_solr, 127.0.0.1:10101_solr, 127.0.0.1:10071_solr, 127.0.0.1:10023_solr, 127.0.0.1:10076_solr, 127.0.0.1:10007_solr, 127.0.0.1:10055_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10070_solr, 127.0.0.1:10077_solr, 127.0.0.1:10038_solr, 127.0.0.1:10032_solr, 127.0.0.1:10093_solr, 127.0.0.1:10061_solr, 127.0.0.1:10067_solr, 127.0.0.1:10086_solr, 127.0.0.1:10089_solr, 127.0.0.1:10045_solr, 127.0.0.1:10042_solr, 127.0.0.1:10029_solr, 127.0.0.1:10083_solr, 127.0.0.1:10080_solr, 127.0.0.1:10048_solr, 127.0.0.1:10064_solr, 127.0.0.1:10043_solr, 127.0.0.1:10057_solr, 127.0.0.1:10074_solr, 127.0.0.1:10026_solr, 127.0.0.1:10012_solr, 127.0.0.1:10060_solr, 127.0.0.1:10073_solr, 127.0.0.1:10058_solr, 127.0.0.1:10013_solr, 127.0.0.1:10090_solr, 127.0.0.1:10088_solr, 127.0.0.1:10027_solr, 127.0.0.1:10039_solr, 127.0.0.1:10025_solr, 127.0.0.1:10044_solr, 127.0.0.1:10028_solr, 127.0.0.1:10092_solr, 127.0.0.1:10041_solr, 127.0.0.1:10087_solr, 127.0.0.1:10009_solr, 127.0.0.1:10030_solr, 127.0.0.1:10014_solr, 127.0.0.1:10011_solr, 127.0.0.1:10040_solr, 127.0.0.1:10085_solr, 127.0.0.1:10046_solr, 127.0.0.1:10068_solr, 127.0.0.1:10063_solr, 127.0.0.1:10015_solr, 127.0.0.1:10069_solr, 127.0.0.1:10062_solr, 127.0.0.1:10008_solr, 127.0.0.1:10024_solr, 127.0.0.1:10050_solr, 127.0.0.1:10075_solr, 127.0.0.1:10078_solr, 127.0.0.1:10097_solr, 127.0.0.1:10031_solr, 127.0.0.1:10034_solr, 127.0.0.1:10091_solr, 127.0.0.1:10094_solr, 127.0.0.1:10100_solr, 127.0.0.1:10037_solr, 127.0.0.1:10053_solr, 127.0.0.1:10059_solr, 127.0.0.1:10103_solr, 127.0.0.1:10056_solr, 127.0.0.1:10072_solr]
[junit4] 2> 3083647 DEBUG (simCloudManagerPool-10354-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10082_solr, 127.0.0.1:10018_solr, 127.0.0.1:10049_solr, 127.0.0.1:10104_solr, 127.0.0.1:10020_solr, 127.0.0.1:10065_solr, 127.0.0.1:10021_solr, 127.0.0.1:10005_solr, 127.0.0.1:10066_solr, 127.0.0.1:10035_solr, 127.0.0.1:10051_solr, 127.0.0.1:10019_solr, 127.0.0.1:10096_solr, 127.0.0.1:10022_solr, 127.0.0.1:10033_solr, 127.0.0.1:10017_solr, 127.0.0.1:10047_solr, 127.0.0.1:10102_solr, 127.0.0.1:10095_solr, 127.0.0.1:10081_solr, 127.0.0.1:10084_solr, 127.0.0.1:10036_solr, 127.0.0.1:10052_solr, 127.0.0.1:10006_solr, 127.0.0.1:10079_solr, 127.0.0.1:10098_solr, 127.0.0.1:10054_solr, 127.0.0.1:10099_solr, 127.0.0.1:10101_solr, 127.0.0.1:10071_solr, 127.0.0.1:10023_solr, 127.0.0.1:10076_solr, 127.0.0.1:10007_solr, 127.0.0.1:10055_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10070_solr, 127.0.0.1:10077_solr, 127.0.0.1:10038_solr, 127.0.0.1:10032_solr, 127.0.0.1:10093_solr, 127.0.0.1:10061_solr, 127.0.0.1:10067_solr, 127.0.0.1:10086_solr, 127.0.0.1:10089_solr, 127.0.0.1:10045_solr, 127.0.0.1:10042_solr, 127.0.0.1:10029_solr, 127.0.0.1:10083_solr, 127.0.0.1:10080_solr, 127.0.0.1:10048_solr, 127.0.0.1:10064_solr, 127.0.0.1:10043_solr, 127.0.0.1:10057_solr, 127.0.0.1:10074_solr, 127.0.0.1:10026_solr, 127.0.0.1:10012_solr, 127.0.0.1:10060_solr, 127.0.0.1:10073_solr, 127.0.0.1:10058_solr, 127.0.0.1:10013_solr, 127.0.0.1:10090_solr, 127.0.0.1:10088_solr, 127.0.0.1:10027_solr, 127.0.0.1:10039_solr, 127.0.0.1:10025_solr, 127.0.0.1:10044_solr, 127.0.0.1:10028_solr, 127.0.0.1:10092_solr, 127.0.0.1:10041_solr, 127.0.0.1:10087_solr, 127.0.0.1:10009_solr, 127.0.0.1:10030_solr, 127.0.0.1:10014_solr, 127.0.0.1:10011_solr, 127.0.0.1:10040_solr, 127.0.0.1:10085_solr, 127.0.0.1:10046_solr, 127.0.0.1:10068_solr, 127.0.0.1:10063_solr, 127.0.0.1:10015_solr, 127.0.0.1:10069_solr, 127.0.0.1:10062_solr, 127.0.0.1:10008_solr, 127.0.0.1:10024_solr, 127.0.0.1:10050_solr, 127.0.0.1:10075_solr, 127.0.0.1:10078_solr, 127.0.0.1:10097_solr, 127.0.0.1:10031_solr, 127.0.0.1:10034_solr, 127.0.0.1:10091_solr, 127.0.0.1:10094_solr, 127.0.0.1:10100_solr, 127.0.0.1:10037_solr, 127.0.0.1:10053_solr, 127.0.0.1:10059_solr, 127.0.0.1:10103_solr, 127.0.0.1:10056_solr, 127.0.0.1:10072_solr]
[junit4] 2> 3083647 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 3
[junit4] 2> 3083648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3083648 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 3, lastZnodeVersion 3
[junit4] 2> 3083648 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083650 DEBUG (simCloudManagerPool-10354-thread-2) [ ] o.a.s.c.a.AutoScalingHandler Verified autoscaling configuration
[junit4] 2> 3083650 DEBUG (simCloudManagerPool-10354-thread-2) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 4
[junit4] 2> 3083651 DEBUG (simCloudManagerPool-10354-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10082_solr, 127.0.0.1:10018_solr, 127.0.0.1:10049_solr, 127.0.0.1:10104_solr, 127.0.0.1:10020_solr, 127.0.0.1:10065_solr, 127.0.0.1:10021_solr, 127.0.0.1:10005_solr, 127.0.0.1:10066_solr, 127.0.0.1:10035_solr, 127.0.0.1:10051_solr, 127.0.0.1:10019_solr, 127.0.0.1:10096_solr, 127.0.0.1:10022_solr, 127.0.0.1:10033_solr, 127.0.0.1:10017_solr, 127.0.0.1:10047_solr, 127.0.0.1:10102_solr, 127.0.0.1:10095_solr, 127.0.0.1:10081_solr, 127.0.0.1:10084_solr, 127.0.0.1:10036_solr, 127.0.0.1:10052_solr, 127.0.0.1:10006_solr, 127.0.0.1:10079_solr, 127.0.0.1:10098_solr, 127.0.0.1:10054_solr, 127.0.0.1:10099_solr, 127.0.0.1:10101_solr, 127.0.0.1:10071_solr, 127.0.0.1:10023_solr, 127.0.0.1:10076_solr, 127.0.0.1:10007_solr, 127.0.0.1:10055_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10070_solr, 127.0.0.1:10077_solr, 127.0.0.1:10038_solr, 127.0.0.1:10032_solr, 127.0.0.1:10093_solr, 127.0.0.1:10061_solr, 127.0.0.1:10067_solr, 127.0.0.1:10086_solr, 127.0.0.1:10089_solr, 127.0.0.1:10045_solr, 127.0.0.1:10042_solr, 127.0.0.1:10029_solr, 127.0.0.1:10083_solr, 127.0.0.1:10080_solr, 127.0.0.1:10048_solr, 127.0.0.1:10064_solr, 127.0.0.1:10043_solr, 127.0.0.1:10057_solr, 127.0.0.1:10074_solr, 127.0.0.1:10026_solr, 127.0.0.1:10012_solr, 127.0.0.1:10060_solr, 127.0.0.1:10073_solr, 127.0.0.1:10058_solr, 127.0.0.1:10013_solr, 127.0.0.1:10090_solr, 127.0.0.1:10088_solr, 127.0.0.1:10027_solr, 127.0.0.1:10039_solr, 127.0.0.1:10025_solr, 127.0.0.1:10044_solr, 127.0.0.1:10028_solr, 127.0.0.1:10092_solr, 127.0.0.1:10041_solr, 127.0.0.1:10087_solr, 127.0.0.1:10009_solr, 127.0.0.1:10030_solr, 127.0.0.1:10014_solr, 127.0.0.1:10011_solr, 127.0.0.1:10040_solr, 127.0.0.1:10085_solr, 127.0.0.1:10046_solr, 127.0.0.1:10068_solr, 127.0.0.1:10063_solr, 127.0.0.1:10015_solr, 127.0.0.1:10069_solr, 127.0.0.1:10062_solr, 127.0.0.1:10008_solr, 127.0.0.1:10024_solr, 127.0.0.1:10050_solr, 127.0.0.1:10075_solr, 127.0.0.1:10078_solr, 127.0.0.1:10097_solr, 127.0.0.1:10031_solr, 127.0.0.1:10034_solr, 127.0.0.1:10091_solr, 127.0.0.1:10094_solr, 127.0.0.1:10100_solr, 127.0.0.1:10037_solr, 127.0.0.1:10053_solr, 127.0.0.1:10059_solr, 127.0.0.1:10103_solr, 127.0.0.1:10056_solr, 127.0.0.1:10072_solr]
[junit4] 2> 3083651 DEBUG (simCloudManagerPool-10354-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Initial livenodes: [127.0.0.1:10082_solr, 127.0.0.1:10018_solr, 127.0.0.1:10049_solr, 127.0.0.1:10104_solr, 127.0.0.1:10020_solr, 127.0.0.1:10065_solr, 127.0.0.1:10021_solr, 127.0.0.1:10005_solr, 127.0.0.1:10066_solr, 127.0.0.1:10035_solr, 127.0.0.1:10051_solr, 127.0.0.1:10019_solr, 127.0.0.1:10096_solr, 127.0.0.1:10022_solr, 127.0.0.1:10033_solr, 127.0.0.1:10017_solr, 127.0.0.1:10047_solr, 127.0.0.1:10102_solr, 127.0.0.1:10095_solr, 127.0.0.1:10081_solr, 127.0.0.1:10084_solr, 127.0.0.1:10036_solr, 127.0.0.1:10052_solr, 127.0.0.1:10006_solr, 127.0.0.1:10079_solr, 127.0.0.1:10098_solr, 127.0.0.1:10054_solr, 127.0.0.1:10099_solr, 127.0.0.1:10101_solr, 127.0.0.1:10071_solr, 127.0.0.1:10023_solr, 127.0.0.1:10076_solr, 127.0.0.1:10007_solr, 127.0.0.1:10055_solr, 127.0.0.1:10010_solr, 127.0.0.1:10016_solr, 127.0.0.1:10070_solr, 127.0.0.1:10077_solr, 127.0.0.1:10038_solr, 127.0.0.1:10032_solr, 127.0.0.1:10093_solr, 127.0.0.1:10061_solr, 127.0.0.1:10067_solr, 127.0.0.1:10086_solr, 127.0.0.1:10089_solr, 127.0.0.1:10045_solr, 127.0.0.1:10042_solr, 127.0.0.1:10029_solr, 127.0.0.1:10083_solr, 127.0.0.1:10080_solr, 127.0.0.1:10048_solr, 127.0.0.1:10064_solr, 127.0.0.1:10043_solr, 127.0.0.1:10057_solr, 127.0.0.1:10074_solr, 127.0.0.1:10026_solr, 127.0.0.1:10012_solr, 127.0.0.1:10060_solr, 127.0.0.1:10073_solr, 127.0.0.1:10058_solr, 127.0.0.1:10013_solr, 127.0.0.1:10090_solr, 127.0.0.1:10088_solr, 127.0.0.1:10027_solr, 127.0.0.1:10039_solr, 127.0.0.1:10025_solr, 127.0.0.1:10044_solr, 127.0.0.1:10028_solr, 127.0.0.1:10092_solr, 127.0.0.1:10041_solr, 127.0.0.1:10087_solr, 127.0.0.1:10009_solr, 127.0.0.1:10030_solr, 127.0.0.1:10014_solr, 127.0.0.1:10011_solr, 127.0.0.1:10040_solr, 127.0.0.1:10085_solr, 127.0.0.1:10046_solr, 127.0.0.1:10068_solr, 127.0.0.1:10063_solr, 127.0.0.1:10015_solr, 127.0.0.1:10069_solr, 127.0.0.1:10062_solr, 127.0.0.1:10008_solr, 127.0.0.1:10024_solr, 127.0.0.1:10050_solr, 127.0.0.1:10075_solr, 127.0.0.1:10078_solr, 127.0.0.1:10097_solr, 127.0.0.1:10031_solr, 127.0.0.1:10034_solr, 127.0.0.1:10091_solr, 127.0.0.1:10094_solr, 127.0.0.1:10100_solr, 127.0.0.1:10037_solr, 127.0.0.1:10053_solr, 127.0.0.1:10059_solr, 127.0.0.1:10103_solr, 127.0.0.1:10056_solr, 127.0.0.1:10072_solr]
[junit4] 2> 3083651 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 4
[junit4] 2> 3083652 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- clean old nodeAdded markers
[junit4] 2> 3083652 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 4, lastZnodeVersion 4
[junit4] 2> 3083667 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083668 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083688 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083690 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083708 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083710 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083729 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083731 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083749 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083751 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083769 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083771 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083790 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083792 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083810 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083812 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083830 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083832 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083851 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083853 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083871 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083873 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083891 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083893 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083912 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083913 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083932 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083934 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083952 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083954 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083973 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083974 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3083993 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3083995 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084013 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084015 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084034 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084035 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084054 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084056 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084074 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084076 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084095 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084096 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084115 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084116 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084135 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084137 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084156 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084157 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084176 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084177 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084196 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084198 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084217 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084218 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084237 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084238 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084257 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084258 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084278 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084279 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084298 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084299 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084318 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084319 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084339 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084340 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084359 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084360 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084379 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084380 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084400 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084401 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084420 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084421 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084441 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084442 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084461 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084462 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084481 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084482 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084502 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084503 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084522 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 100
[junit4] 2> 3084523 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 100
[junit4] 2> 3084527 INFO (TEST-TestLargeCluster.testBasic-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.TestLargeCluster Ready after 37891ms
[junit4] 2> 3084533 DEBUG (simCloudManagerPool-10354-thread-79) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testBasic / shard2: {"core_node18":{
[junit4] 2> "node_name":"127.0.0.1:10090_solr",
[junit4] 2> "core":"testBasic_shard2_replica_n18",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testBasic"}}
[junit4] 2> 3084535 DEBUG (simCloudManagerPool-10354-thread-82) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testBasic / shard5: {"core_node65":{
[junit4] 2> "node_name":"127.0.0.1:10038_solr",
[junit4] 2> "core":"testBasic_shard5_replica_n65",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard5",
[junit4] 2> "collection":"testBasic"}}
[junit4] 2> 3084535 DEBUG (simCloudManagerPool-10354-thread-81) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testBasic / shard4: {"core_node54":{
[junit4] 2> "node_name":"127.0.0.1:10023_solr",
[junit4] 2> "core":"testBasic_shard4_replica_t54",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"TLOG",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard4",
[junit4] 2> "collection":"testBasic"}}
[junit4] 2> 3084533 DEBUG (simCloudManagerPool-10354-thread-80) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testBasic / shard3: {"core_node39":{
[junit4] 2> "node_name":"127.0.0.1:10070_solr",
[junit4] 2> "core":"testBasic_shard3_replica_t39",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"TLOG",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"testBasic"}}
[junit4] 2> 3084541 DEBUG (simCloudManagerPool-10354-thread-83) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testBasic / shard1: {"core_node1":{
[junit4] 2> "node_name":"127.0.0.1:10073_solr",
[junit4] 2> "core":"testBasic_shard1_replica_n1",
[junit4] 2> "leader":"true",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "INDEX.sizeInBytes":123450000,
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testBasic"}}
[junit4] 2> 3084545 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 98
[junit4] 2> 3084549 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 98
[junit4] 2> 3084553 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10104_solr
[junit4] 2> 3084555 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10104_solr
[junit4] 2> 3084555 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10060_solr
[junit4] 2> 3084556 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10060_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10036_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10036_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10099_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10099_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10061_solr
[junit4] 2> 3084579 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10061_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10086_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10074_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10086_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10040_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10074_solr
[junit4] 2> 3084580 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10040_solr
[junit4] 2> 3084600 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3084601 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3084621 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3084621 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3084641 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3084642 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3084662 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3084662 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3084662 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10104_solr, 127.0.0.1:10060_solr]
[junit4] 2> 3084662 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"b1b5046ed33d8T56oh6jw9pr2gtsrn98jp03avk",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126256345101272,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126256345101272,
[junit4] 2> 3126256439319722],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3084666 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"b1b5046ed33d8T56oh6jw9pr2gtsrn98jp03avk",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126256345101272,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126256345101272,
[junit4] 2> 3126256439319722],
[junit4] 2> "_enqueue_time_":3126261644484472,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3084668 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"b1b5046ed33d8T56oh6jw9pr2gtsrn98jp03avk",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126256345101272,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126256345101272,
[junit4] 2> 3126256439319722],
[junit4] 2> "_enqueue_time_":3126261644484472,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}} with context properties: {BEFORE_ACTION=[compute]}
[junit4] 2> 3084690 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10072_solr&inPlaceMove=true&replica=core_node31
[junit4] 2> 3084694 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10056_solr&inPlaceMove=true&replica=core_node41
[junit4] 2> 3084694 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3126263230 sessionWrapper.createTime 3126262091835972, this.sessionWrapper.createTime 3126262091835972
[junit4] 2> 3084694 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"b1b5046ed33d8T56oh6jw9pr2gtsrn98jp03avk",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126256345101272,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126256345101272,
[junit4] 2> 3126256439319722],
[junit4] 2> "_enqueue_time_":3126261644484472,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@7a07ff, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@bde440], AFTER_ACTION=[compute], BEFORE_ACTION=[compute, execute]}
[junit4] 2> 3084695 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10072_solr&inPlaceMove=true&replica=core_node31
[junit4] 2> 3084796 DEBUG (simCloudManagerPool-10354-thread-120) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node77":{
[junit4] 2> "core":"testBasic_shard3_replica_n76",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"testBasic",
[junit4] 2> "node_name":"127.0.0.1:10072_solr",
[junit4] 2> "type":"NRT"}}
[junit4] 2> 3084909 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10056_solr&inPlaceMove=true&replica=core_node41
[junit4] 2> 3085010 DEBUG (simCloudManagerPool-10354-thread-128) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node79":{
[junit4] 2> "core":"testBasic_shard3_replica_p78",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"testBasic",
[junit4] 2> "node_name":"127.0.0.1:10056_solr",
[junit4] 2> "type":"PULL"}}
[junit4] 2> 3085123 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 22846 ms for event id=b1b5046ed33d8T56oh6jw9pr2gtsrn98jp03avk
[junit4] 2> 3085125 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085129 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085129 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085129 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03avn",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085130 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085145 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085150 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085151 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085151 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03avp",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085151 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085166 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085166 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10104_solr, 127.0.0.1:10060_solr]
[junit4] 2> 3085166 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b504365deb8T56oh6jw9pr2gtsrn98jp03avr",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126256285900472,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126256285900472,
[junit4] 2> 3126256431627722],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085167 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10104_solr, 127.0.0.1:10060_solr] is not ready, will try later
[junit4] 2> 3085172 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085172 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085172 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03avt",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085173 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085187 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085187 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10104_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr, 127.0.0.1:10060_solr]
[junit4] 2> 3085188 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03avv",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085188 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10104_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr, 127.0.0.1:10060_solr] is not ready, will try later
[junit4] 2> 3085193 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085194 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085194 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03avx",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085195 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085209 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085209 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10104_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr, 127.0.0.1:10060_solr]
[junit4] 2> 3085209 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03avz",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085210 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10104_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr, 127.0.0.1:10060_solr] is not ready, will try later
[junit4] 2> 3085215 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085215 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085215 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03aw1",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085216 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085230 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085230 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10104_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr, 127.0.0.1:10060_solr]
[junit4] 2> 3085231 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085231 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "_enqueue_time_":3126290054330172,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085231 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "_enqueue_time_":3126290054330172,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}} with context properties: {BEFORE_ACTION=[auto_add_replicas_plan]}
[junit4] 2> 3085234 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3126290216 sessionWrapper.createTime 3126290202361372, this.sessionWrapper.createTime 3126290202361372
[junit4] 2> 3085234 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "_enqueue_time_":3126290054330172,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}} with context properties: {AFTER_ACTION=[auto_add_replicas_plan], BEFORE_ACTION=[auto_add_replicas_plan, execute_plan]}
[junit4] 2> 3085234 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction No operations to execute for event: {
[junit4] 2> "id":"b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":3126257536684222,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257536684222,
[junit4] 2> 3126257503754272,
[junit4] 2> 3126256285900472,
[junit4] 2> 3126257493913222,
[junit4] 2> 3126257532049772,
[junit4] 2> 3126257518131722,
[junit4] 2> 3126257478340772,
[junit4] 2> 3126256431627722],
[junit4] 2> "_enqueue_time_":3126290054330172,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10104_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr",
[junit4] 2> "127.0.0.1:10060_solr"]}}
[junit4] 2> 3085235 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 194 ms for event id=b1b508df350beT56oh6jw9pr2gtsrn98jp03aw3
[junit4] 2> 3085236 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085236 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085237 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03aw6",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085237 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085251 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085257 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085258 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085258 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03aw8",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085258 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085272 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085279 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085279 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085279 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awa",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085279 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085292 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085300 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085300 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085300 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awc",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085300 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085312 DEBUG (ScheduledTrigger-10355-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085321 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085321 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085321 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.ScheduledTriggers -------- Cooldown period - rejecting event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awe",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085321 DEBUG (ScheduledTrigger-10355-thread-3) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr] is not ready, will try later
[junit4] 2> 3085333 DEBUG (ScheduledTrigger-10355-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 92
[junit4] 2> 3085342 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: node_lost_trigger with currently live nodes: 92
[junit4] 2> 3085342 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10040_solr, 127.0.0.1:10061_solr, 127.0.0.1:10099_solr, 127.0.0.1:10074_solr, 127.0.0.1:10086_solr, 127.0.0.1:10036_solr]
[junit4] 2> 3085342 DEBUG (ScheduledTrigger-10355-thread-2) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awg",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085343 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awg",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "_enqueue_time_":3126295630580972,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}}
[junit4] 2> 3085343 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awg",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "_enqueue_time_":3126295630580972,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}} with context properties: {BEFORE_ACTION=[compute]}
[junit4] 2> 3085361 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10103_solr&inPlaceMove=true&replica=core_node43
[junit4] 2> 3085371 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10059_solr&inPlaceMove=true&replica=core_node36
[junit4] 2> 3085378 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10053_solr&inPlaceMove=true&replica=core_node60
[junit4] 2> 3085384 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10037_solr&inPlaceMove=true&replica=core_node56
[junit4] 2> 3085387 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10100_solr&inPlaceMove=true&replica=core_node27
[junit4] 2> 3085389 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10094_solr&inPlaceMove=true&replica=core_node32
[junit4] 2> 3085389 INFO (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 3126297990 sessionWrapper.createTime 3126295782835772, this.sessionWrapper.createTime 3126295782835772
[junit4] 2> 3085390 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"b1b508d1b77b6T56oh6jw9pr2gtsrn98jp03awg",
[junit4] 2> "source":"node_lost_trigger",
[junit4] 2> "eventTime":3126257522538422,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[
[junit4] 2> 3126257522538422,
[junit4] 2> 3126257498861722,
[junit4] 2> 3126257487507572,
[junit4] 2> 3126257511706672,
[junit4] 2> 3126257507805872,
[junit4] 2> 3126257483207472],
[junit4] 2> "_enqueue_time_":3126295630580972,
[junit4] 2> "nodeNames":[
[junit4] 2> "127.0.0.1:10040_solr",
[junit4] 2> "127.0.0.1:10061_solr",
[junit4] 2> "127.0.0.1:10099_solr",
[junit4] 2> "127.0.0.1:10074_solr",
[junit4] 2> "127.0.0.1:10086_solr",
[junit4] 2> "127.0.0.1:10036_solr"]}} with context properties: {operations=[org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@111bf66, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1d9114a, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@13975e8, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@147073a, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@1b17d3b, org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica@f37346], AFTER_ACTION=[compute], BEFORE_ACTION=[compute, execute]}
[junit4] 2> 3085390 DEBUG (AutoscalingActionExecutor-10356-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testBasic&targetNode=127.0.0.1:10103_solr&inPlaceMove=true&replica=core_node43
[junit4] 2> 3085491 DEBUG (simCloudManagerPool-10354-thread-153) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node81":{
[junit4] 2> "core":"testBasic_shard3_replica_p80",
[junit4] 2> "shard":"shard3",
[junit4] 2> "collection":"testBasic",
[junit4] 2> "node_name":"127.0.0.1:10103_solr",
[junit4] 2> "type":"PULL"}}
[junit4] 2> 3085603 DEBUG (Autoscaling
[...truncated too long message...]
FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## Total replicas: 300
[junit4] 2> 3116985 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * testNodeAdded 300
[junit4] 2> 3116985 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - active 300
[junit4] 2> 3116985 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Final Solr op counts ##########
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - CREATE 1
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - DELETESTATUS 60
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - MOVEREPLICA 60
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - REQUESTSTATUS 60
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - autoscaling 1
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - update 22
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ######### Autoscaling event counts ###########
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## * Trigger: node_added_trigger
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - IGNORED 14
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - STARTED 4
[junit4] 2> 3116986 INFO (TEST-TestLargeCluster.testAddNode-seed#[53FF2FBC4B6F58FB]) [ ] o.a.s.c.a.s.SimSolrCloudTestCase ## - SUCCEEDED 4
[junit4] IGNOR/A 0.00s J1 | TestLargeCluster.testSearchRate
[junit4] > Assumption #1: 'awaitsfix' test group is disabled (@AwaitsFix(bugUrl=https://issues.apache.org/jira/browse/SOLR-11714))
[junit4] 2> 3116989 WARN (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 3116989 DEBUG (SUITE-TestLargeCluster-seed#[53FF2FBC4B6F58FB]-worker) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.autoscaling.sim.TestLargeCluster_53FF2FBC4B6F58FB-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1970, maxMBSortInHeap=7.116927059772913, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1fffc14), locale=it-CH, timezone=Pacific/Truk
[junit4] 2> NOTE: Linux 4.10.0-40-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=1,free=94477624,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [SolrIndexMetricsTest, TestJettySolrRunner, TestLegacyField, DistribDocExpirationUpdateProcessorTest, TestRebalanceLeaders, AtomicUpdateProcessorFactoryTest, DistributedTermsComponentTest, SimpleCollectionCreateDeleteTest, TestHdfsUpdateLog, SampleTest, TestSchemaVersionResource, TestRuleBasedAuthorizationPlugin, TestBM25SimilarityFactory, TestCursorMarkWithoutUniqueKey, OutputWriterTest, TestPayloadScoreQParserPlugin, DebugComponentTest, SolrJmxReporterTest, MetricUtilsTest, BaseCdcrDistributedZkTest, TestFieldResource, SchemaVersionSpecificBehaviorTest, SearchHandlerTest, TestAtomicUpdateErrorCases, TestLegacyFieldCache, RestartWhileUpdatingTest, ZkCLITest, TestTrieFacet, DocumentAnalysisRequestHandlerTest, TestRTGBase, TestSolrCLIRunExample, TestSolr4Spatial, CloudExitableDirectoryReaderTest, QueryEqualityTest, TestDocumentBuilder, VMParamsZkACLAndCredentialsProvidersTest, DistributedIntervalFacetingTest, TestTlogReplica, TestHashQParserPlugin, EnumFieldTest, TestSmileRequest, TestPivotHelperCode, HLLSerializationTest, AutoscalingHistoryHandlerTest, TestSubQueryTransformerDistrib, SuggesterFSTTest, HighlighterConfigTest, TestDistribIDF, DocValuesMultiTest, DistributedQueryComponentOptimizationTest, ShardRoutingTest, BJQParserTest, BlockJoinFacetSimpleTest, TestPseudoReturnFields, TestRawTransformer, CreateCollectionCleanupTest, HdfsDirectoryTest, PropertiesRequestHandlerTest, LargeFieldTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestStressRecovery, SOLR749Test, AutoAddReplicasPlanActionTest, TestJmxIntegration, DistributedFacetPivotLargeTest, MoreLikeThisHandlerTest, TestClusterProperties, PathHierarchyTokenizerFactoryTest, BitVectorTest, HdfsTlogReplayBufferedWhileIndexingTest, TestSchemalessBufferedUpdates, MetricTriggerTest, DeleteLastCustomShardedReplicaTest, HdfsNNFailoverTest, PKIAuthenticationIntegrationTest, CircularListTest, QueryResultKeyTest, SpellCheckCollatorWithCollapseTest, TestDistribStateManager, OpenCloseCoreStressTest, TestManagedSchemaThreadSafety, TestImpersonationWithHadoopAuth, TestPolicyCloud, TestJavabinTupleStreamParser, TestPullReplicaErrorHandling, ShardRoutingCustomTest, TestSolrQueryParser, TestMaxTokenLenTokenizer, PingRequestHandlerTest, TestSystemCollAutoCreate, DistributedDebugComponentTest, TestAnalyzedSuggestions, CollectionTooManyReplicasTest, ConvertedLegacyTest, DirectUpdateHandlerTest, TestJsonRequest, TestNumericRangeQuery64, LeaderInitiatedRecoveryOnShardRestartTest, TestNamedUpdateProcessors, ClassificationUpdateProcessorIntegrationTest, DirectoryFactoryTest, TestClassicSimilarityFactory, AssignTest, TestCloudManagedSchema, TestLRUStatsCache, DocExpirationUpdateProcessorFactoryTest, CdcrUpdateLogTest, TestRequestStatusCollectionAPI, LeaderFailoverAfterPartitionTest, ShowFileRequestHandlerTest, TestLuceneMatchVersion, TestSchemaNameResource, SolrRequestParserTest, TestSimpleTextCodec, MBeansHandlerTest, RulesTest, TestCryptoKeys, TestManagedStopFilterFactory, SearchRateTriggerTest, TestOnReconnectListenerSupport, SolrShardReporterTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, ZkSolrClientTest, TestRandomDVFaceting, TestDistributedGrouping, TermVectorComponentDistributedTest, TestRealTimeGet, TestStressReorder, SimpleFacetsTest, SolrCoreTest, TestGroupingSearch, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, TestFiltering, TestFunctionQuery, TestLazyCores, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SpellCheckCollatorTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, SuggesterTest, TestStressLucene, TestTrie, TestCSVLoader, PolyFieldTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestUpdate, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DistanceFunctionTest, TestSurroundQueryParser, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestWriterPerf, TestReversedWildcardFilterFactory, TestOmitPositions, XmlUpdateRequestHandlerTest, RequestHandlersTest, TermVectorComponentTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, RegexBoostProcessorTest, SolrPluginUtilsTest, IndexSchemaTest, TestCollationField, ReturnFieldsTest, TestCSVResponseWriter, QueryParsingTest, JsonLoaderTest, BinaryUpdateRequestHandlerTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, TestQuerySenderNoQuery, ResponseLogComponentTest, SolrIndexConfigTest, TestMergePolicyConfig, MultiTermTest, TestDocSet, TestBinaryField, NumericFieldsTest, TestConfig, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, TestCodecSupport, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TestFastWriter, ResourceLoaderTest, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, TestFastLRUCache, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, AsyncCallRequestStatusResponseTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, ConcurrentDeleteAndCreateCollectionTest, CustomCollectionTest, DeleteInactiveReplicaTest, DeleteNodeTest, DeleteShardTest, DistributedVersionInfoTest, HealthCheckHandlerTest, LeaderElectionContextKeyTest, LeaderFailureAfterFreshStartTest, LeaderInitiatedRecoveryOnCommitTest, MigrateRouteKeyTest, MoveReplicaHDFSTest, OverriddenZkACLAndCredentialsProvidersTest, PeerSyncReplicationTest, SharedFSAutoReplicaFailoverTest, SolrXmlInZkTest, TestAuthenticationFramework, TestCloudInspectUtil, TestCloudJSONFacetJoinDomain, TestCloudPivotFacet, TestCloudPseudoReturnFields, TestCloudRecovery, TestCloudSearcherWarming, TestCollectionsAPIViaSolrCloudCluster, TestConfigSetsAPI, TestConfigSetsAPIExclusivity, TestDownShardTolerantSearch, TestExclusionRuleCollectionAccess, TestLeaderElectionWithEmptyReplica, TestLocalFSCloudBackupRestore, TestLockTree, TestMiniSolrCloudClusterSSL, TestRandomRequestDistribution, TestReplicaProperties, TestShortCircuitedRequests, TestSizeLimitedDistributedMap, TestSolrCloudWithDelegationTokens, TestStressCloudBlindAtomicUpdates, TriLevelCompositeIdRoutingTest, AutoScalingHandlerTest, ComputePlanActionTest, ExecutePlanActionTest, TestLargeCluster]
[junit4] Completed [586/766 (1!)] on J1 in 33.50s, 4 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 44469 lines...]