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 2017/08/31 04:17:09 UTC
[JENKINS] Lucene-Solr-6.6-Linux (32bit/jdk1.8.0_144) - Build # 118
- Still Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/118/
Java: 32bit/jdk1.8.0_144 -server -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI
Error Message:
Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
Stack Trace:
java.lang.AssertionError: Something is broken in the assert for no shards using the same indexDir - probably something was changed in the attributes published in the MBean of SolrCore : {}
at __randomizedtesting.SeedInfo.seed([D34B71906AB4C2A7:9B3E05246C87ED32]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.checkNoTwoShardsUseTheSameIndexDir(CollectionsAPIDistributedZkTest.java:646)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:524)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
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 11472 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/init-core-data-001
[junit4] 2> 383609 WARN (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 383609 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 383610 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 383611 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001
[junit4] 2> 383611 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 383616 INFO (Thread-835) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 383616 INFO (Thread-835) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 383626 ERROR (Thread-835) [ ] 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> 383716 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44069
[junit4] 2> 383762 INFO (jetty-launcher-491-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 383774 INFO (jetty-launcher-491-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 383775 INFO (jetty-launcher-491-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 383787 INFO (jetty-launcher-491-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 383792 INFO (jetty-launcher-491-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4b1f11{/solr,null,AVAILABLE}
[junit4] 2> 383796 INFO (jetty-launcher-491-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@16d8a35{/solr,null,AVAILABLE}
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@14cc7cb{SSL,[ssl, http/1.1]}{127.0.0.1:43135}
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.e.j.s.Server Started @385698ms
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43135}
[junit4] 2> 383799 ERROR (jetty-launcher-491-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 383799 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T03:38:41.373Z
[junit4] 2> 383803 INFO (jetty-launcher-491-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@885a2{/solr,null,AVAILABLE}
[junit4] 2> 383803 INFO (jetty-launcher-491-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e274f0{SSL,[ssl, http/1.1]}{127.0.0.1:46759}
[junit4] 2> 383810 INFO (jetty-launcher-491-thread-2) [ ] o.e.j.s.Server Started @385710ms
[junit4] 2> 383810 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46759}
[junit4] 2> 383811 ERROR (jetty-launcher-491-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@10deedc{SSL,[ssl, http/1.1]}{127.0.0.1:39495}
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.e.j.s.Server Started @385710ms
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39495}
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1258708{/solr,null,AVAILABLE}
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T03:38:41.385Z
[junit4] 2> 383811 ERROR (jetty-launcher-491-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T03:38:41.385Z
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2d39a8{SSL,[ssl, http/1.1]}{127.0.0.1:34357}
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-4) [ ] o.e.j.s.Server Started @385711ms
[junit4] 2> 383811 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34357}
[junit4] 2> 383811 ERROR (jetty-launcher-491-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 383812 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.6.1
[junit4] 2> 383812 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 383812 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 383812 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T03:38:41.386Z
[junit4] 2> 383817 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 383840 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 383840 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 383841 INFO (jetty-launcher-491-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44069/solr
[junit4] 2> 383841 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 383842 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 383878 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 383879 INFO (jetty-launcher-491-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44069/solr
[junit4] 2> 383903 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 383906 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 383909 INFO (jetty-launcher-491-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44069/solr
[junit4] 2> 383910 INFO (jetty-launcher-491-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44069/solr
[junit4] 2> 383939 INFO (jetty-launcher-491-thread-3) [n:127.0.0.1:43135_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 383939 INFO (jetty-launcher-491-thread-1) [n:127.0.0.1:39495_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 383940 INFO (jetty-launcher-491-thread-4) [n:127.0.0.1:34357_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 383941 INFO (jetty-launcher-491-thread-4) [n:127.0.0.1:34357_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34357_solr
[junit4] 2> 383941 INFO (jetty-launcher-491-thread-2) [n:127.0.0.1:46759_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 383942 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 383945 INFO (jetty-launcher-491-thread-1) [n:127.0.0.1:39495_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:39495_solr
[junit4] 2> 383949 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 383949 INFO (zkCallback-511-thread-1-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 383951 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 383956 INFO (jetty-launcher-491-thread-1) [n:127.0.0.1:39495_solr ] o.a.s.c.Overseer Overseer (id=98576021663973386-127.0.0.1:39495_solr-n_0000000000) starting
[junit4] 2> 383956 INFO (jetty-launcher-491-thread-3) [n:127.0.0.1:43135_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43135_solr
[junit4] 2> 383956 INFO (jetty-launcher-491-thread-2) [n:127.0.0.1:46759_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46759_solr
[junit4] 2> 383956 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 383956 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 383956 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 383956 INFO (zkCallback-511-thread-1-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (3)
[junit4] 2> 384002 INFO (jetty-launcher-491-thread-1) [n:127.0.0.1:39495_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39495_solr
[junit4] 2> 384003 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 384010 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 384015 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 384021 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 384063 INFO (jetty-launcher-491-thread-2) [n:127.0.0.1:46759_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node2/.
[junit4] 2> 384126 INFO (jetty-launcher-491-thread-3) [n:127.0.0.1:43135_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node3/.
[junit4] 2> 384138 INFO (jetty-launcher-491-thread-4) [n:127.0.0.1:34357_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node4/.
[junit4] 2> 384199 INFO (jetty-launcher-491-thread-1) [n:127.0.0.1:39495_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node1/.
[junit4] 2> 384222 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 384222 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44069/solr ready
[junit4] 2> 384253 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D34B71906AB4C2A7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testTooManyReplicas
[junit4] 2> 384255 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D34B71906AB4C2A7]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 384333 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 384335 INFO (OverseerThreadFactory-1521-thread-1-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.CreateCollectionCmd Create collection collection
[junit4] 2> 384340 WARN (OverseerThreadFactory-1521-thread-1-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.CreateCollectionCmd Specified replicationFactor of 10 on collection collection is higher than or equal to the number of Solr instances currently live or live and part of your createNodeSet(4). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 384340 ERROR (OverseerThreadFactory-1521-thread-1-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.OverseerCollectionMessageHandler Collection: collection operation: create failed:org.apache.solr.common.SolrException: Cannot create collection collection. Value of maxShardsPerNode is 1, and the number of nodes currently live or live and part of your createNodeSet is 4. This allows a maximum of 4 to be created. Value of numShards is 2 and value of replicationFactor is 10. This requires 20 shards to be created (higher than the allowed number)
[junit4] 2> at org.apache.solr.cloud.CreateCollectionCmd.call(CreateCollectionCmd.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionMessageHandler.processMessage(OverseerCollectionMessageHandler.java:226)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:464)
[junit4] 2> at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 384367 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=10&collection.configName=conf&name=collection&action=CREATE&numShards=2&wt=javabin&version=2} status=400 QTime=34
[junit4] 2> 384368 INFO (OverseerCollectionConfigSetProcessor-98576021663973386-127.0.0.1:39495_solr-n_0000000000) [n:127.0.0.1:39495_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 384374 INFO (TEST-CollectionsAPIDistributedZkTest.testTooManyReplicas-seed#[D34B71906AB4C2A7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testTooManyReplicas
[junit4] 2> 384409 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[D34B71906AB4C2A7]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCollectionReload
[junit4] 2> 384410 INFO (TEST-CollectionsAPIDistributedZkTest.testCollectionReload-seed#[D34B71906AB4C2A7]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 384418 INFO (qtp8788182-3333) [n:127.0.0.1:34357_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=conf&name=reloaded_collection&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 384421 INFO (OverseerThreadFactory-1521-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.CreateCollectionCmd Create collection reloaded_collection
[junit4] 2> 384581 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 384582 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 384679 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 384680 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 384682 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2
[junit4] 2> 384682 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 384684 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2
[junit4] 2> 384685 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 384799 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 384799 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 384799 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 384799 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 385602 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 385614 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica1] Schema name=minimal
[junit4] 2> 385634 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 385634 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica1' using configuration from collection reloaded_collection, trusted=true
[junit4] 2> 385634 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 385634 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node4/reloaded_collection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node4/./reloaded_collection_shard2_replica1/data/]
[junit4] 2> 385677 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 385677 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 385678 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 385679 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 385687 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f62e60[reloaded_collection_shard2_replica1] main]
[junit4] 2> 385688 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 385688 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 385689 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 385689 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216348796223488
[junit4] 2> 385691 INFO (searcherExecutor-1530-thread-1-processing-n:127.0.0.1:34357_solr x:reloaded_collection_shard2_replica1 s:shard2 c:reloaded_collection) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] Registered new searcher Searcher@1f62e60[reloaded_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 385710 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 385750 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 385824 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 385824 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica2] Schema name=minimal
[junit4] 2> 385834 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 385834 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica2' using configuration from collection reloaded_collection, trusted=true
[junit4] 2> 385834 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 385834 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node1/reloaded_collection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node1/./reloaded_collection_shard1_replica2/data/]
[junit4] 2> 385837 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica1] Schema name=minimal
[junit4] 2> 385853 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 385853 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard1_replica1' using configuration from collection reloaded_collection, trusted=true
[junit4] 2> 385853 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 385853 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node2/reloaded_collection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node2/./reloaded_collection_shard1_replica1/data/]
[junit4] 2> 385853 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica2] Schema name=minimal
[junit4] 2> 385855 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 385855 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'reloaded_collection_shard2_replica2' using configuration from collection reloaded_collection, trusted=true
[junit4] 2> 385855 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 385855 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node3/reloaded_collection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node3/./reloaded_collection_shard2_replica2/data/]
[junit4] 2> 385855 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 385938 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 385938 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 385939 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 385939 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 385939 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1cd58c[reloaded_collection_shard1_replica2] main]
[junit4] 2> 385947 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 385947 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 385947 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 385947 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216349066756096
[junit4] 2> 385952 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9998ms
[junit4] 2> 385952 INFO (searcherExecutor-1535-thread-1-processing-n:127.0.0.1:39495_solr x:reloaded_collection_shard1_replica2 s:shard1 c:reloaded_collection) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] Registered new searcher Searcher@1cd58c[reloaded_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 385998 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 385998 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 385999 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 385999 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 386000 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@105714c[reloaded_collection_shard1_replica1] main]
[junit4] 2> 386001 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 386001 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 386001 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 386006 INFO (searcherExecutor-1536-thread-1-processing-n:127.0.0.1:46759_solr x:reloaded_collection_shard1_replica1 s:shard1 c:reloaded_collection) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [reloaded_collection_shard1_replica1] Registered new searcher Searcher@105714c[reloaded_collection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 386007 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216349129670656
[junit4] 2> 386021 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 386021 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 386022 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 386022 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 386023 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@16a818e[reloaded_collection_shard2_replica2] main]
[junit4] 2> 386024 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 386025 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 386025 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 386026 INFO (searcherExecutor-1537-thread-1-processing-n:127.0.0.1:43135_solr x:reloaded_collection_shard2_replica2 s:shard2 c:reloaded_collection) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [reloaded_collection_shard2_replica2] Registered new searcher Searcher@16a818e[reloaded_collection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 386026 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216349149593600
[junit4] 2> 386056 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386056 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386056 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386056 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386356 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 386356 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 386356 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34357/solr/reloaded_collection_shard2_replica1/
[junit4] 2> 386356 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard2_replica1 url=https://127.0.0.1:34357/solr START replicas=[https://127.0.0.1:43135/solr/reloaded_collection_shard2_replica2/] nUpdates=100
[junit4] 2> 386356 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard2_replica1 url=https://127.0.0.1:34357/solr DONE. We have no versions. sync failed.
[junit4] 2> 386380 INFO (qtp26524825-3310) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.c.S.Request [reloaded_collection_shard2_replica2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 386380 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 386380 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] 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> 386380 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 386382 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34357/solr/reloaded_collection_shard2_replica1/ shard2
[junit4] 2> 386452 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 386453 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 386453 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:39495/solr/reloaded_collection_shard1_replica2/
[junit4] 2> 386453 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica2 url=https://127.0.0.1:39495/solr START replicas=[https://127.0.0.1:46759/solr/reloaded_collection_shard1_replica1/] nUpdates=100
[junit4] 2> 386453 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=reloaded_collection_shard1_replica2 url=https://127.0.0.1:39495/solr DONE. We have no versions. sync failed.
[junit4] 2> 386460 INFO (qtp5023871-3326) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.c.S.Request [reloaded_collection_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 386460 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 386460 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] 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> 386460 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 386464 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:39495/solr/reloaded_collection_shard1_replica2/ shard1
[junit4] 2> 386574 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386574 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386574 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386575 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386582 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 386583 INFO (qtp8788182-3300) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=2003
[junit4] 2> 386620 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 386623 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=1943
[junit4] 2> 386731 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386731 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386731 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 386731 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 387011 INFO (qtp5023871-3328) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 x:reloaded_collection_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard1_replica1&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=2329
[junit4] 2> 387031 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 x:reloaded_collection_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf&newCollection=true&name=reloaded_collection_shard2_replica2&action=CREATE&numShards=2&collection=reloaded_collection&shard=shard2&wt=javabin&version=2} status=0 QTime=2346
[junit4] 2> 387033 INFO (qtp8788182-3333) [n:127.0.0.1:34357_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> 387161 INFO (zkCallback-504-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 387161 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 387161 INFO (zkCallback-511-thread-2-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 387162 INFO (zkCallback-512-thread-1-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/reloaded_collection/state.json] for collection [reloaded_collection] has occurred - updating... (live nodes size: [4])
[junit4] 2> 388033 INFO (qtp8788182-3333) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=conf&name=reloaded_collection&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3615
[junit4] 2> 388039 INFO (qtp21011430-3322) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388042 INFO (qtp5023871-3325) [n:127.0.0.1:46759_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388048 INFO (qtp8788182-3301) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388060 INFO (qtp26524825-3312) [n:127.0.0.1:43135_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388065 INFO (qtp8788182-3334) [n:127.0.0.1:34357_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :reload with params async=7e163e71-eb0d-4f23-a6ac-942bd3af959a&name=reloaded_collection&action=RELOAD&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 388065 INFO (qtp8788182-3334) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=7e163e71-eb0d-4f23-a6ac-942bd3af959a&name=reloaded_collection&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388072 INFO (qtp21011430-3317) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388072 INFO (OverseerThreadFactory-1521-thread-3-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.OverseerCollectionMessageHandler Executing Collection Cmd : action=RELOAD
[junit4] 2> 388072 INFO (OverseerCollectionConfigSetProcessor-98576021663973386-127.0.0.1:39495_solr-n_0000000000) [n:127.0.0.1:39495_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 388074 INFO (qtp5023871-3315) [n:127.0.0.1:46759_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=reloaded_collection_shard1_replica1&async=7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388074 INFO (qtp21011430-3298) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=reloaded_collection_shard1_replica2&async=7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388075 INFO (qtp26524825-3304) [n:127.0.0.1:43135_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=reloaded_collection_shard2_replica2&async=7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388077 INFO (qtp8788182-3335) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=reloaded_collection_shard2_replica1&async=7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 388083 INFO (qtp5023871-3325) [n:127.0.0.1:46759_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388083 INFO (qtp21011430-3317) [n:127.0.0.1:39495_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064
[junit4] 2> 388087 INFO (qtp21011430-3317) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=3
[junit4] 2> 388099 INFO (qtp8788182-3302) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388107 INFO (qtp26524825-3304) [n:127.0.0.1:43135_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388110 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 388110 INFO (qtp21011430-3321) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388132 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 388146 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 388185 INFO (qtp5023871-3316) [n:127.0.0.1:46759_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388185 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr ] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica2] Schema name=minimal
[junit4] 2> 388190 INFO (qtp8788182-3335) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388191 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 388206 INFO (qtp26524825-3306) [n:127.0.0.1:43135_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388210 INFO (qtp21011430-3299) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388211 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 388211 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'reloaded_collection_shard1_replica2' using configuration from collection reloaded_collection
[junit4] 2> 388255 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node1/reloaded_collection_shard1_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node1/./reloaded_collection_shard1_replica2/data/]
[junit4] 2> 388259 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr ] o.a.s.s.IndexSchema [reloaded_collection_shard1_replica1] Schema name=minimal
[junit4] 2> 388287 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 388287 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'reloaded_collection_shard1_replica1' using configuration from collection reloaded_collection
[junit4] 2> 388290 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard1_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node2/reloaded_collection_shard1_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node2/./reloaded_collection_shard1_replica1/data/]
[junit4] 2> 388297 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr ] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica1] Schema name=minimal
[junit4] 2> 388302 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr ] o.a.s.s.IndexSchema [reloaded_collection_shard2_replica2] Schema name=minimal
[junit4] 2> 388329 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 388329 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'reloaded_collection_shard2_replica2' using configuration from collection reloaded_collection
[junit4] 2> 388330 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node3/reloaded_collection_shard2_replica2], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node3/./reloaded_collection_shard2_replica2/data/]
[junit4] 2> 388351 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 388351 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr ] o.a.s.c.CoreContainer Reloading SolrCore 'reloaded_collection_shard2_replica1' using configuration from collection reloaded_collection
[junit4] 2> 388352 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [[reloaded_collection_shard2_replica1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node4/reloaded_collection_shard2_replica1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001/tempDir-001/node4/./reloaded_collection_shard2_replica1/data/]
[junit4] 2> 388353 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 388353 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 388383 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1a922a5[reloaded_collection_shard1_replica2] main]
[junit4] 2> 388386 INFO (qtp5023871-3327) [n:127.0.0.1:46759_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388388 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 388388 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 388388 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 388388 INFO (searcherExecutor-1550-thread-1-processing-x:reloaded_collection_shard1_replica2 r:core_node2 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD n:127.0.0.1:39495_solr s:shard1 c:reloaded_collection) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] Registered new searcher Searcher@1a922a5[reloaded_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388394 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216351632621568
[junit4] 2> 388400 INFO (qtp8788182-3334) [n:127.0.0.1:34357_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388443 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 388443 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 388447 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@ad124a[reloaded_collection_shard2_replica1] main]
[junit4] 2> 388450 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 388450 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 388450 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 388453 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216351694487552
[junit4] 2> 388461 INFO (searcherExecutor-1554-thread-1-processing-x:reloaded_collection_shard2_replica1 r:core_node1 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD n:127.0.0.1:34357_solr s:shard2 c:reloaded_collection) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] Registered new searcher Searcher@ad124a[reloaded_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388465 INFO (qtp26524825-3307) [n:127.0.0.1:43135_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388485 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 388485 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 388485 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 388486 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@17ccd4a[reloaded_collection_shard2_replica1] main]
[junit4] 2> 388486 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@9329ba
[junit4] 2> 388493 INFO (searcherExecutor-1554-thread-1-processing-x:reloaded_collection_shard2_replica1 r:core_node1 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD n:127.0.0.1:34357_solr s:shard2 c:reloaded_collection) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.c.SolrCore [reloaded_collection_shard2_replica1] Registered new searcher Searcher@17ccd4a[reloaded_collection_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388503 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 388503 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 388507 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 388508 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1de2276[reloaded_collection_shard1_replica2] main]
[junit4] 2> 388508 INFO (parallelCoreAdminExecutor-1525-thread-1-processing-n:127.0.0.1:34357_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865866651 RELOAD) [n:127.0.0.1:34357_solr c:reloaded_collection s:shard2 r:core_node1 x:reloaded_collection_shard2_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.reloaded_collection.shard2.replica1
[junit4] 2> 388508 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1b36d79
[junit4] 2> 388509 INFO (searcherExecutor-1550-thread-1-processing-x:reloaded_collection_shard1_replica2 r:core_node2 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD n:127.0.0.1:39495_solr s:shard1 c:reloaded_collection) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.c.SolrCore [reloaded_collection_shard1_replica2] Registered new searcher Searcher@1de2276[reloaded_collection_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388508 INFO (qtp21011430-3317) [n:127.0.0.1:39495_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=false&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 388510 INFO (parallelCoreAdminExecutor-1528-thread-1-processing-n:127.0.0.1:39495_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865672064 RELOAD) [n:127.0.0.1:39495_solr c:reloaded_collection s:shard1 r:core_node2 x:reloaded_collection_shard1_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.reloaded_collection.shard1.replica2
[junit4] 2> 388511 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@d8826a[reloaded_collection_shard1_replica1] main]
[junit4] 2> 388511 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@e4bb0b[reloaded_collection_shard2_replica2] main]
[junit4] 2> 388512 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 388512 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 388512 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 388513 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 388513 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 388513 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 388513 INFO (searcherExecutor-1552-thread-1-processing-x:reloaded_collection_shard2_replica2 r:core_node4 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD n:127.0.0.1:43135_solr s:shard2 c:reloaded_collection) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.c.SolrCore [reloaded_collection_shard2_replica2] Registered new searcher Searcher@e4bb0b[reloaded_collection_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388513 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216351757402112
[junit4] 2> 388513 INFO (parallelCoreAdminExecutor-1524-thread-1-processing-n:127.0.0.1:43135_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865918390 RELOAD) [n:127.0.0.1:43135_solr c:reloaded_collection s:shard2 r:core_node4 x:reloaded_collection_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577216351757402112
[junit4] 2> 388515 INFO (searcherExecutor-1551-thread-1-processing-x:reloaded_collection_shard1_replica1 r:core_node3 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD n:127.0.0.1:46759_solr s:shard1 c:reloaded_collection) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [reloaded_collection_shard1_replica1] Registered new searcher Searcher@d8826a[reloaded_collection_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 388527 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 388527 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@b27bef[reloaded_collection_shard1_replica1] main]
[junit4] 2> 388527 INFO (parallelCoreAdminExecutor-1522-thread-1-processing-n:127.0.0.1:46759_solr 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD) [n:127.0.0.1:46759_solr c:reloaded_collection s:shard1 r:core_node3 x:reloaded_collection_shard1_replica1] o.a.s.c.SolrCore [reloaded_collection_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1c94b65
[junit4] 2> 388528 INFO (searcherExecutor-1551-thread-1-processing-x:reloaded_collection_shard1_replica1 r:core_node3 7e163e71-eb0d-4f23-a6ac-942bd3af959a69563865808172 RELOAD n:127.0.0.1:46759_solr s:shard1 c:rel
[...truncated too long message...]
singRequiredParameters-seed#[D34B71906AB4C2A7]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testMissingRequiredParameters
[junit4] 2> 495524 INFO (jetty-closer-492-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2d5078{SSL,[ssl, http/1.1]}{127.0.0.1:43135}
[junit4] 2> 495524 INFO (jetty-closer-492-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1e274f0{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 495524 INFO (jetty-closer-492-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=33198188
[junit4] 2> 495524 INFO (jetty-closer-492-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 495524 INFO (jetty-closer-492-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 495524 INFO (jetty-closer-492-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 495527 INFO (jetty-closer-492-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=7027487
[junit4] 2> 495527 INFO (jetty-closer-492-thread-4) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@10deedc{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 495527 INFO (jetty-closer-492-thread-4) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=17751696
[junit4] 2> 495527 INFO (jetty-closer-492-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 495527 INFO (jetty-closer-492-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 495527 INFO (jetty-closer-492-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 495527 INFO (jetty-closer-492-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 495527 INFO (jetty-closer-492-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 495527 INFO (jetty-closer-492-thread-4) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 495531 WARN (zkCallback-512-thread-3-processing-n:127.0.0.1:46759_solr) [n:127.0.0.1:46759_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 495532 INFO (jetty-closer-492-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@885a2{/solr,null,UNAVAILABLE}
[junit4] 2> 495532 INFO (jetty-closer-492-thread-4) [ ] o.a.s.c.Overseer Overseer (id=98576021663973386-127.0.0.1:39495_solr-n_0000000000) closing
[junit4] 2> 495532 INFO (OverseerStateUpdate-98576021663973386-127.0.0.1:39495_solr-n_0000000000) [n:127.0.0.1:39495_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:39495_solr
[junit4] 2> 495535 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 495535 INFO (zkCallback-511-thread-6-processing-n:127.0.0.1:39495_solr) [n:127.0.0.1:39495_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (3)
[junit4] 2> 495535 INFO (zkCallback-513-thread-1-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (1)
[junit4] 2> 495536 INFO (jetty-closer-492-thread-4) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@16d8a35{/solr,null,UNAVAILABLE}
[junit4] 2> 495536 INFO (zkCallback-513-thread-2-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:34357_solr
[junit4] 2> 495536 INFO (zkCallback-513-thread-2-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.Overseer Overseer (id=98576021663973388-127.0.0.1:34357_solr-n_0000000002) starting
[junit4] 2> 495539 INFO (jetty-closer-492-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2d39a8{SSL,[ssl, http/1.1]}{127.0.0.1:0}
[junit4] 2> 495539 INFO (jetty-closer-492-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=4744109
[junit4] 2> 495539 INFO (jetty-closer-492-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 495539 INFO (jetty-closer-492-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 495539 INFO (jetty-closer-492-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 495542 INFO (jetty-closer-492-thread-3) [ ] o.a.s.c.Overseer Overseer (id=98576021663973388-127.0.0.1:34357_solr-n_0000000002) closing
[junit4] 2> 495543 INFO (OverseerStateUpdate-98576021663973388-127.0.0.1:34357_solr-n_0000000002) [n:127.0.0.1:34357_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:34357_solr
[junit4] 2> 497035 WARN (zkCallback-537-thread-1-processing-n:127.0.0.1:43135_solr) [n:127.0.0.1:43135_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 497035 INFO (jetty-closer-492-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@e1fff7{/solr,null,UNAVAILABLE}
[junit4] 2> 497044 WARN (zkCallback-513-thread-2-processing-n:127.0.0.1:34357_solr) [n:127.0.0.1:34357_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 497044 INFO (jetty-closer-492-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1258708{/solr,null,UNAVAILABLE}
[junit4] 2> 497044 ERROR (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-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> 497044 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:44069 44069
[junit4] 2> 497174 INFO (Thread-835) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:44069 44069
[junit4] 2> 497175 WARN (Thread-835) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 26 /solr/aliases.json
[junit4] 2> 23 /solr/configs/conf
[junit4] 2> 5 /solr/security.json
[junit4] 2> 3 /solr/configs/conf2
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 299 /solr/clusterstate.json
[junit4] 2> 26 /solr/clusterprops.json
[junit4] 2> 4 /solr/collections/nodes_used_collection/state.json
[junit4] 2> 4 /solr/collections/addReplicaColl/state.json
[junit4] 2> 4 /solr/collections/reloaded_collection/state.json
[junit4] 2> 3 /solr/collections/awhollynewcollection_0/state.json
[junit4] 2> 3 /solr/collections/acollectionafterbaddelete/state.json
[junit4] 2> 2 /solr/collections/onlyinzk/state.json
[junit4] 2> 2 /solr/overseer_elect/election/98576021663973386-127.0.0.1:39495_solr-n_0000000000
[junit4] 2> 2 /solr/collections/halfdeletedcollection/state.json
[junit4] 2> 2 /solr/collections/addReplicaColl/leader_elect/shard1/election/98576021663973393-core_node2-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 484 /solr/collections
[junit4] 2> 47 /solr/live_nodes
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 497175 INFO (SUITE-CollectionsAPIDistributedZkTest-seed#[D34B71906AB4C2A7]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_D34B71906AB4C2A7-001
[junit4] 2> Aug 31, 2017 3:40:34 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=true,coord=yes): {}, locale=es-SV, timezone=Asia/Phnom_Penh
[junit4] 2> NOTE: Linux 4.10.0-33-generic i386/Oracle Corporation 1.8.0_144 (32-bit)/cpus=8,threads=1,free=29402776,total=149237760
[junit4] 2> NOTE: All tests run in this JVM: [TestDistributedGrouping, UUIDUpdateProcessorFallbackTest, TestLeaderElectionZkExpiry, SolrJmxReporterCloudTest, TestObjectReleaseTracker, TestRandomRequestDistribution, SampleTest, SmileWriterTest, DistributedFacetPivotLargeTest, TriLevelCompositeIdRoutingTest, TestCloudPivotFacet, TestJsonFacetRefinement, TestFileDictionaryLookup, BooleanFieldTest, DeleteInactiveReplicaTest, TestTrieFacet, DistributedTermsComponentTest, TestSolrFieldCacheMBean, TestSQLHandlerNonCloud, TestEmbeddedSolrServerConstructors, TestCollationFieldDocValues, PKIAuthenticationIntegrationTest, TestCloudManagedSchema, TestChildDocTransformer, DocValuesMissingTest, TermsComponentTest, TestSystemCollAutoCreate, TestCustomDocTransformer, TestNoOpRegenerator, CollectionsAPISolrJTest, CoreAdminRequestStatusTest, TestNumericTerms64, CSVRequestHandlerTest, TestCopyFieldCollectionResource, SpellCheckComponentTest, ChaosMonkeySafeLeaderTest, CollectionStateFormat2Test, CollectionsAPIDistributedZkTest]
[junit4] Completed [155/713 (1!)] on J1 in 113.84s, 20 tests, 1 failure <<< FAILURES!
[...truncated 41328 lines...]
[JENKINS-EA] Lucene-Solr-6.6-Linux (64bit/jdk-9-ea+181) - Build #
119 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.6-Linux/119/
Java: 64bit/jdk-9-ea+181 -XX:-UseCompressedOops -XX:+UseG1GC --illegal-access=deny
1 tests failed.
FAILED: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test
Error Message:
document count mismatch. control=691 sum(shards)=685 cloudClient=685
Stack Trace:
java.lang.AssertionError: document count mismatch. control=691 sum(shards)=685 cloudClient=685
at __randomizedtesting.SeedInfo.seed([8CAE2226992DF5FD:4FA1DFC37D19805]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1323)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:226)
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:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
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:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.base/java.lang.Thread.run(Thread.java:844)
Build Log:
[...truncated 12544 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/init-core-data-001
[junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8CAE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8CAE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="https://issues.apache.org/jira/browse/SOLR-5776")
[junit4] 2> 1284002 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8CAE2226992DF5FD]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 1284004 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 1284006 INFO (Thread-3543) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1284006 INFO (Thread-3543) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 1284011 ERROR (Thread-3543) [ ] 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> 1284106 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer start zk server on port:46749
[junit4] 2> 1284110 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1284111 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1284111 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1284112 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1284113 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1284113 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1284114 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1284115 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1284115 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractZkTestCase put /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1284191 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores/collection1
[junit4] 2> 1284192 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1284193 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2f6d6b29{/,null,AVAILABLE}
[junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@54b4044{HTTP/1.1,[http/1.1]}{127.0.0.1:၃၅၆၇၁}
[junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @၁၂၈၆၅၇၁ms
[junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/control/data, hostPort=35671, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores}
[junit4] 2> 1284194 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1284194 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1284195 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T08:38:29.550044Z
[junit4] 2> 1284198 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1284198 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/solr.xml
[junit4] 2> 1284202 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1284202 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46749/solr
[junit4] 2> 1284208 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1284209 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35671_
[junit4] 2> 1284209 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=98577200536748036-127.0.0.1:35671_-n_0000000000) starting
[junit4] 2> 1284211 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35671_
[junit4] 2> 1284214 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1284232 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores
[junit4] 2> 1284232 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1284233 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1284234 INFO (OverseerStateUpdate-98577200536748036-127.0.0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1285241 WARN (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1285241 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1285254 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1285364 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1285413 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection, trusted=true
[junit4] 2> 1285413 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1285414 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/control-001/cores/collection1/data/]
[junit4] 2> 1285414 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420
[junit4] 2> 1285416 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1285521 WARN (coreLoadExecutor-5045-thread-1) [ ] 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> 1285547 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1285547 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1285548 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@34e0f71c[collection1] main]
[junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1285549 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1285550 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1285550 INFO (searcherExecutor-5046-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@34e0f71c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1285550 INFO (coreLoadExecutor-5045-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577235210205921280
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:35671/collection1/
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:35671/collection1/ has no replicas
[junit4] 2> 1285553 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1285554 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:35671/collection1/ shard1
[junit4] 2> 1285705 INFO (coreZkRegister-5038-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:46749/solr ready
[junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1285740 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating collection1 with stateFormat=2
[junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores/collection1
[junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001
[junit4] 2> 1285810 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1285811 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@61856d9c{/,null,AVAILABLE}
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@511abcbe{HTTP/1.1,[http/1.1]}{127.0.0.1:၃၆၈၇၅}
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @၁၂၈၈၁၈၉ms
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty1, hostPort=36875, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores}
[junit4] 2> 1285812 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1285812 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T08:38:31.167769Z
[junit4] 2> 1285814 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1285814 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/solr.xml
[junit4] 2> 1285817 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1285817 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46749/solr
[junit4] 2> 1285821 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 1285821 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1285822 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36875_
[junit4] 2> 1285823 INFO (zkCallback-2074-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1285825 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1285826 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 1285851 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores
[junit4] 2> 1285851 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1285851 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1285854 INFO (OverseerStateUpdate-98577200536748036-127.0.0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 1285955 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1286864 WARN (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1286865 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1286875 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1286954 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1286968 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true
[junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-1-001/cores/collection1/data/]
[junit4] 2> 1286969 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420
[junit4] 2> 1286970 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1287069 WARN (coreLoadExecutor-5056-thread-1) [ ] 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> 1287087 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 1287088 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1287089 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1287089 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@38707c64[collection1] main]
[junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1287090 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1287090 INFO (searcherExecutor-5057-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@38707c64[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1287091 INFO (coreLoadExecutor-5056-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577235211821776896
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36875/collection1/
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:36875/collection1/ has no replicas
[junit4] 2> 1287094 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1287095 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36875/collection1/ shard2
[junit4] 2> 1287196 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1287245 INFO (coreZkRegister-5051-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1287350 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 1287432 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores/collection1
[junit4] 2> 1287432 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001
[junit4] 2> 1287433 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@18c5422e{/,null,AVAILABLE}
[junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@419e10e3{HTTP/1.1,[http/1.1]}{127.0.0.1:၄၁၉၉၅}
[junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @၁၂၈၉၈၁၁ms
[junit4] 2> 1287434 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty2, hostPort=41995, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores}
[junit4] 2> 1287434 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1287435 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T08:38:32.790209Z
[junit4] 2> 1287441 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1287441 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/solr.xml
[junit4] 2> 1287445 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1287445 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46749/solr
[junit4] 2> 1287449 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 1287450 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1287450 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41995_
[junit4] 2> 1287453 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1287453 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1287453 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1287453 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 1287470 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores
[junit4] 2> 1287470 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1287471 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1287471 INFO (OverseerStateUpdate-98577200536748036-127.0.0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1287572 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1287573 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1288476 WARN (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1288476 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1288492 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1288536 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true
[junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-2-001/cores/collection1/data/]
[junit4] 2> 1288550 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420
[junit4] 2> 1288551 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1288575 WARN (coreLoadExecutor-5067-thread-1) [ ] 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> 1288595 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1288595 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1288603 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 1288603 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3b9aba89[collection1] main]
[junit4] 2> 1288604 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1288605 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1288605 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1288605 INFO (searcherExecutor-5068-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3b9aba89[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1288606 INFO (coreLoadExecutor-5067-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577235213410369536
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41995/collection1/
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.SyncStrategy http://127.0.0.1:41995/collection1/ has no replicas
[junit4] 2> 1288608 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR
[junit4] 2> 1288609 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41995/collection1/ shard1
[junit4] 2> 1288710 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1288710 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1288714 INFO (coreZkRegister-5062-thread-1) [ ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 1288815 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1288815 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [3])
[junit4] 2> 1289025 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores/collection1
[junit4] 2> 1289026 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001
[junit4] 2> 1289026 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1289027 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e005ad4{/,null,AVAILABLE}
[junit4] 2> 1289027 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@36ade7e7{HTTP/1.1,[http/1.1]}{127.0.0.1:၄၅၀၂၃}
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @၁၂၉၁၄၀၅ms
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty3, hostPort=45023, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores}
[junit4] 2> 1289028 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1289028 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T08:38:34.383605Z
[junit4] 2> 1289029 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1289029 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/solr.xml
[junit4] 2> 1289033 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1289034 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46749/solr
[junit4] 2> 1289037 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 1289038 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1289039 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45023_
[junit4] 2> 1289039 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1289039 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1289039 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1289039 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1289039 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 1289061 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores
[junit4] 2> 1289061 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1289062 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1289063 INFO (OverseerStateUpdate-98577200536748036-127.0.0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2
[junit4] 2> 1289164 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1289164 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1289164 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1290069 WARN (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1290069 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1290085 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1290152 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true
[junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1290158 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-3-001/cores/collection1/data/]
[junit4] 2> 1290159 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420
[junit4] 2> 1290160 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1290179 WARN (coreLoadExecutor-5078-thread-1) [ ] 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> 1290199 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1290199 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1290200 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@175e64d5[collection1] main]
[junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1290201 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1290202 INFO (searcherExecutor-5079-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@175e64d5[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1290202 INFO (coreLoadExecutor-5078-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577235215083896832
[junit4] 2> 1290204 INFO (coreZkRegister-5073-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 1290204 INFO (updateExecutor-2093-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1290204 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:36875/collection1/] and I am [http://127.0.0.1:45023/collection1/]
[junit4] 2> 1290205 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:36875]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:45023_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 1290206 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1290207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard2 of collection1) have state: recovering
[junit4] 2> 1290207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:45023_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:45023","node_name":"127.0.0.1:45023_","state":"down"}
[junit4] 2> 1290306 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1290306 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1290306 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [4])
[junit4] 2> 1290625 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores/collection1
[junit4] 2> 1290626 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001
[junit4] 2> 1290626 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@562cc620{/,null,AVAILABLE}
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2e363e3f{HTTP/1.1,[http/1.1]}{127.0.0.1:၃၈၆၂၇}
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.Server Started @၁၂၉၃၀၀၄ms
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/tempDir-001/jetty4, hostPort=38627, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores}
[junit4] 2> 1290627 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 6.6.1
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 1290627 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-08-31T08:38:35.982982Z
[junit4] 2> 1290629 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 1290629 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/solr.xml
[junit4] 2> 1290632 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1290632 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:46749/solr
[junit4] 2> 1290644 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 1290645 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 1290645 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38627_
[junit4] 2> 1290646 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290646 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290646 INFO (zkCallback-2078-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290646 INFO (zkCallback-2074-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290646 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290646 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 1290665 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores
[junit4] 2> 1290665 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 1290667 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 1290668 INFO (OverseerStateUpdate-98577200536748036-127.0.0.1:35671_-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
[junit4] 2> 1290771 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1290771 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1290771 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1290771 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:45023_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:45023","node_name":"127.0.0.1:45023_","state":"recovering"}
[junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1291207 INFO (qtp1986792501-12293) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:45023_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node3&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1000
[junit4] 2> 1291686 WARN (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead.
[junit4] 2> 1291686 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.6.1
[junit4] 2> 1291693 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1291707 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:36875/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 1291707 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:45023 START replicas=[http://127.0.0.1:36875/collection1/] nUpdates=100
[junit4] 2> 1291710 INFO (qtp1986792501-12293) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1291710 INFO (qtp1986792501-12293) [ ] o.a.s.c.S.Request [collection1] webapp= path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 1291711 INFO (recoveryExecutor-2094-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 1291746 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.6 with uniqueid field id
[junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection collection1, trusted=true
[junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores/collection1], dataDir=[/home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001/shard-4-001/cores/collection1/data/]
[junit4] 2> 1291752 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61c3f420
[junit4] 2> 1291753 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=48, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1291772 WARN (coreLoadExecutor-5089-thread-1) [ ] 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> 1291790 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 1291790 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 15000ms;
[junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1291796 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@630699e2[collection1] main]
[junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1291797 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1291798 INFO (searcherExecutor-5090-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@630699e2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1291798 INFO (coreLoadExecutor-5089-thread-1) [ ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1577235216757424128
[junit4] 2> 1291800 INFO (coreZkRegister-5084-thread-1) [ ] o.a.s.c.ZkController Core needs to recover:collection1
[junit4] 2> 1291800 INFO (updateExecutor-2100-thread-1) [ ] o.a.s.u.DefaultSolrCoreState Running recovery
[junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Starting recovery process. recoveringAfterStartup=true
[junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy ###### startupVersions=[[]]
[junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[collection1]
[junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 1291800 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Publishing state of core [collection1] as recovering, leader is [http://127.0.0.1:41995/collection1/] and I am [http://127.0.0.1:38627/collection1/]
[junit4] 2> 1291801 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:41995]; [WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1:38627_&coreNodeName=core_node4&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
[junit4] 2> 1291802 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
[junit4] 2> 1291806 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRecoveryOp Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 1291806 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:38627_, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:38627","node_name":"127.0.0.1:38627_","state":"down"}
[junit4] 2> 1291902 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1291902 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1291902 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1291902 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1292169 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.SolrTestCaseJ4 ###Starting test
[junit4] 2> 1292169 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):330
[junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:38627_, coreNodeName=core_node4, onlyIfActiveCheckResult=false, nodeProps: core_node4:{"core":"collection1","base_url":"http://127.0.0.1:38627","node_name":"127.0.0.1:38627_","state":"recovering"}
[junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.h.a.PrepRecoveryOp Waited coreNodeName: core_node4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 1292807 INFO (qtp15989041-12321) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:38627_&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node4&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=1004
[junit4] 2> 1293307 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:41995/collection1/] - recoveringAfterStartup=[true]
[junit4] 2> 1293307 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.PeerSync PeerSync: core=collection1 url=http://127.0.0.1:38627 START replicas=[http://127.0.0.1:41995/collection1/] nUpdates=100
[junit4] 2> 1293308 INFO (qtp15989041-12317) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1293308 INFO (qtp15989041-12317) [ ] o.a.s.c.S.Request [collection1] webapp= path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.IndexFingerprint IndexFingerprint millis:0.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=0, maxInHash=0, versionsHash=0, numVersions=0, numDocs=0, maxDoc=0}
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy PeerSync stage of recovery was successful.
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Replaying updates buffered during PeerSync.
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy No replay needed.
[junit4] 2> 1293309 INFO (recoveryExecutor-2101-thread-1) [ ] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
[junit4] 2> 1293411 INFO (zkCallback-2096-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1293411 INFO (zkCallback-2090-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1293411 INFO (zkCallback-2103-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1293411 INFO (zkCallback-2084-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [5])
[junit4] 2> 1294170 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 1294177 INFO (qtp1935364758-12255) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1577235219245694976)} 0 6
[junit4] 2> 1294221 INFO (qtp678145122-12349) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1577235219265617920&distrib.from=http://127.0.0.1:36875/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1577235219265617920)} 0 25
[junit4] 2> 1294222 INFO (qtp1986792501-12291) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1577235219265617920)} 0 31
[junit4] 2> 1294231 INFO (qtp166102078-12383) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1577235219253035008&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{deleteByQuery=*:* (-1577235219253035008)} 0 9
[junit4] 2> 1294232 INFO (qtp15989041-12316) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1577235219253035008)} 0 53
[junit4] 2> 1294240 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: starting
[junit4] 2> 1294241 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: Jetty will not commit on close
[junit4] 2> 1294252 INFO (qtp1935364758-12256) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-0 (1577235219328532480)]} 0 1
[junit4] 2> 1294266 INFO (qtp1986792501-12290) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={df=text&distrib=false&_stateVer_=collection1:10&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:36875/collection1/|http://127.0.0.1:45023/collection1/&rows=10&version=2&q=aid&NOW=1504168719610&isShard=true&wt=javabin} hits=0 status=0 QTime=0
[junit4] 2> 1294268 INFO (qtp166102078-12384) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{add=[0-0 (1577235219332726784)]} 0 0
[junit4] 2> 1294268 INFO (qtp15989041-12321) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{add=[0-0 (1577235219332726784)]} 0 14
[junit4] 2> 1294270 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-1 (1577235219349504000)]} 0 0
[junit4] 2> 1294279 INFO (qtp166102078-12384) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{add=[0-1 (1577235219351601152)]} 0 0
[junit4] 2> 1294279 INFO (qtp15989041-12318) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{add=[0-1 (1577235219351601152)]} 0 7
[junit4] 2> 1294286 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{delete=[0-1 (-1577235219366281216)]} 0 0
[junit4] 2> 1294289 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{delete=[0-1 (-1577235219368378368)]} 0 0
[junit4] 2> 1294290 INFO (qtp15989041-12319) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{delete=[0-1 (-1577235219368378368)]} 0 2
[junit4] 2> 1294292 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-2 (1577235219372572672)]} 0 0
[junit4] 2> 1294293 INFO (qtp15989041-12322) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={df=text&distrib=false&_stateVer_=collection1:10&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:41995/collection1/|http://127.0.0.1:38627/collection1/&rows=10&version=2&q=aid&NOW=1504168719610&isShard=true&wt=javabin} hits=0 status=0 QTime=0
[junit4] 2> 1294294 INFO (qtp15989041-12323) [ ] o.a.s.c.S.Request [collection1] webapp= path=/select params={q=aid&_stateVer_=collection1:10&wt=javabin&version=2} hits=0 status=0 QTime=38
[junit4] 2> 1294296 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{add=[0-2 (1577235219374669824)]} 0 0
[junit4] 2> 1294296 INFO (qtp15989041-12321) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{add=[0-2 (1577235219374669824)]} 0 2
[junit4] 2> 1294298 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-3 (1577235219378864128)]} 0 0
[junit4] 2> 1294303 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{add=[0-3 (1577235219380961280)]} 0 0
[junit4] 2> 1294303 INFO (qtp15989041-12322) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2}{add=[0-3 (1577235219380961280)]} 0 2
[junit4] 2> 1294305 INFO (qtp1935364758-12250) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={wt=javabin&version=2&CONTROL=TRUE}{add=[0-4 (1577235219385155584)]} 0 0
[junit4] 2> 1294310 INFO (qtp166102078-12378) [ ] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41995/collection1/&wt=javabin&version=2}{add=[0-4 (1577235219388301312)]} 0 0
[junit4] 2> 1294317
[...truncated too long message...]
O (zkCallback-2096-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1335304 INFO (zkCallback-2096-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 1336685 WARN (zkCallback-2110-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 1336685 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@d57c427{HTTP/1.1,[http/1.1]}{127.0.0.1:၄၁၉၉၅}
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@68ad453{/,null,UNAVAILABLE}
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 45023
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=688558845
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jvm
[junit4] 2> 1336686 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.jetty
[junit4] 2> 1336697 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.Overseer Overseer (id=98577200536748047-127.0.0.1:45023_-n_0000000003) closing
[junit4] 2> 1336697 INFO (OverseerStateUpdate-98577200536748047-127.0.0.1:45023_-n_0000000003) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:45023_
[junit4] 2> 1337657 WARN (zkCallback-2096-thread-6) [ ] o.a.s.c.SyncStrategy Closed, skipping sync up.
[junit4] 2> 1337658 INFO (zkCallback-2096-thread-6) [ ] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@35094441
[junit4] 2> 1337671 INFO (zkCallback-2096-thread-6) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1
[junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@36ade7e7{HTTP/1.1,[http/1.1]}{127.0.0.1:၀}
[junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@e005ad4{/,null,UNAVAILABLE}
[junit4] 2> 1337672 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 38627
[junit4] 2> 1337672 ERROR (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] 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> 1337673 INFO (TEST-ChaosMonkeyNothingIsSafeTest.test-seed#[8CAE2226992DF5FD]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46749 46749
[junit4] 2> 1342685 INFO (Thread-3614) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:46749 46749
[junit4] 2> 1342685 WARN (Thread-3614) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/overseer/queue
[junit4] 2> 2 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=test -Dtests.seed=8CAE2226992DF5FD -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=my -Dtests.timezone=Etc/Greenwich -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 58.7s J2 | ChaosMonkeyNothingIsSafeTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: document count mismatch. control=691 sum(shards)=685 cloudClient=685
[junit4] > at __randomizedtesting.SeedInfo.seed([8CAE2226992DF5FD:4FA1DFC37D19805]:0)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1323)
[junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.test(ChaosMonkeyNothingIsSafeTest.java:226)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:564)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:992)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:844)
[junit4] 2> 1342688 INFO (SUITE-ChaosMonkeyNothingIsSafeTest-seed#[8CAE2226992DF5FD]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-6.6-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.ChaosMonkeyNothingIsSafeTest_8CAE2226992DF5FD-001
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=false,coord=no): {}, locale=my, timezone=Etc/Greenwich
[junit4] 2> NOTE: Linux 4.10.0-33-generic amd64/Oracle Corporation 9 (64-bit)/cpus=8,threads=1,free=168463480,total=520093696
[junit4] 2> NOTE: All tests run in this JVM: [AsyncCallRequestStatusResponseTest, SubstringBytesRefFilterTest, LukeRequestHandlerTest, V2ApiIntegrationTest, TestSchemaNameResource, MultiThreadedOCPTest, TestSolrJ, SolrJmxReporterTest, DeleteLastCustomShardedReplicaTest, CloudExitableDirectoryReaderTest, AutoCommitTest, SortSpecParsingTest, TestConfigSetImmutable, CollectionTooManyReplicasTest, OverseerTest, TestFieldCacheSortRandom, TestRestoreCore, EnumFieldTest, SpellPossibilityIteratorTest, FieldMutatingUpdateProcessorTest, TestNamedUpdateProcessors, TestCorePropertiesReload, ReplicaListTransformerTest, HttpPartitionTest, SolrCoreCheckLockOnStartupTest, TestWriterPerf, TestStressReorder, SolrGangliaReporterTest, SolrTestCaseJ4Test, TestSolrConfigHandlerCloud, TestHashQParserPlugin, QueryResultKeyTest, TestCoreDiscovery, TestSearcherReuse, TestShortCircuitedRequests, DocExpirationUpdateProcessorFactoryTest, LargeFieldTest, UpdateLogTest, TestJsonFacets, TestExportWriter, OpenExchangeRatesOrgProviderTest, TestRawTransformer, TimeZoneUtilsTest, MinimalSchemaTest, TestIndexSearcher, TestPostingsSolrHighlighter, TestLegacyFieldCache, TestHalfAndHalfDocValues, TestUtils, HdfsTlogReplayBufferedWhileIndexingTest, StatsComponentTest, TestReload, PreAnalyzedFieldTest, SuggesterTSTTest, TestNRTOpen, DistribDocExpirationUpdateProcessorTest, DocValuesMultiTest, TestHdfsBackupRestoreCore, LeaderFailureAfterFreshStartTest, BinaryUpdateRequestHandlerTest, TestRTimerTree, ZkStateWriterTest, TestSimpleTextCodec, TestSolr4Spatial2, DistributedFacetPivotLongTailTest, CoreMergeIndexesAdminHandlerTest, CoreAdminHandlerTest, SimpleCollectionCreateDeleteTest, AtomicUpdateProcessorFactoryTest, TestSchemalessBufferedUpdates, PrimUtilsTest, TestCollationField, CdcrVersionReplicationTest, DirectUpdateHandlerOptimizeTest, BlockDirectoryTest, PluginInfoTest, TestManagedSchemaThreadSafety, TestCollectionAPI, TestSolrCloudWithKerberosAlt, AnalyticsMergeStrategyTest, TestTolerantUpdateProcessorRandomCloud, SuggesterTest, TestMergePolicyConfig, QueryParsingTest, TestStandardQParsers, TestIndexingPerformance, TestDFRSimilarityFactory, TestFreeTextSuggestions, ReplaceNodeTest, DeleteShardTest, TestBulkSchemaAPI, HardAutoCommitTest, HdfsNNFailoverTest, RecoveryZkTest, TestQueryWrapperFilter, ActionThrottleTest, OverriddenZkACLAndCredentialsProvidersTest, RequestLoggingTest, TestBinaryField, DistributedVersionInfoTest, ClassificationUpdateProcessorIntegrationTest, SolrIndexMetricsTest, TestOnReconnectListenerSupport, TestHdfsUpdateLog, CachingDirectoryFactoryTest, DistributedSuggestComponentTest, FieldAnalysisRequestHandlerTest, TestJavabinTupleStreamParser, PreAnalyzedUpdateProcessorTest, BasicDistributedZk2Test, TermVectorComponentDistributedTest, DOMUtilTest, XmlUpdateRequestHandlerTest, BadComponentTest, PeerSyncReplicationTest, TestFieldSortValues, ShardRoutingTest, ClusterStateUpdateTest, TestZkChroot, TestDistributedSearch, DisMaxRequestHandlerTest, TestReversedWildcardFilterFactory, PrimitiveFieldTypeTest, DocumentBuilderTest, TermVectorComponentTest, TestSolrQueryParser, LoggingHandlerTest, SolrPluginUtilsTest, UpdateRequestProcessorFactoryTest, MBeansHandlerTest, JsonLoaderTest, TestPartialUpdateDeduplication, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, TestQuerySenderListener, AlternateDirectoryTest, ResponseLogComponentTest, SampleTest, TestDocSet, OutputWriterTest, ExternalFileFieldSortTest, TestPhraseSuggestions, TestLMJelinekMercerSimilarityFactory, ResourceLoaderTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed [490/713 (1!)] on J2 in 58.70s, 1 test, 1 failure <<< FAILURES!
[...truncated 37126 lines...]