Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.x-Java7/3695/
1 tests failed. FAILED: org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior Error Message: Illegal state, was: down expected:active clusterState:live nodes:[]collections:{c1=DocCollection(c1)={ "router":{"name":"implicit"}, "shards":{"shard1":{ "range":null, "state":"active", "parent":null, "replicas":{"core_node1":{ "base_url":"http://127.0.0.1/solr", "node_name":"node1", "core":"core1", "roles":"", "state":"down"}}}}}, test=LazyCollectionRef(test)} Stack Trace: java.lang.AssertionError: Illegal state, was: down expected:active clusterState:live nodes:[]collections:{c1=DocCollection(c1)={ "router":{"name":"implicit"}, "shards":{"shard1":{ "range":null, "state":"active", "parent":null, "replicas":{"core_node1":{ "base_url":"http://127.0.0.1/solr", "node_name":"node1", "core":"core1", "roles":"", "state":"down"}}}}}, test=LazyCollectionRef(test)} at __randomizedtesting.SeedInfo.seed([51C979EA21C2E92:6D029472408C74DC]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.OverseerTest.verifyStatus(OverseerTest.java:601) at org.apache.solr.cloud.OverseerTest.testExternalClusterStateChangeBehavior(OverseerTest.java:1261) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1660) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:866) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:902) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:875) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:777) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:811) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:822) 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:46) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) 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:54) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367) at java.lang.Thread.run(Thread.java:745) Build Log: [...truncated 10657 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerTest_51C979EA21C2E92-001/init-core-data-001 [junit4] 2> 1085522 INFO (SUITE-OverseerTest-seed#[51C979EA21C2E92]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) [junit4] 2> 1085522 INFO (SUITE-OverseerTest-seed#[51C979EA21C2E92]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore [junit4] 2> 1085522 INFO (SUITE-OverseerTest-seed#[51C979EA21C2E92]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end [junit4] 2> 1085526 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testPlaceholders [junit4] 2> 1085526 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1085527 INFO (Thread-5963) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1085527 INFO (Thread-5963) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1085627 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer start zk server on port:49393 [junit4] 2> 1085627 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1085644 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1085657 INFO (zkCallback-677-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2216aa76 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1085657 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1085657 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1085657 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1085663 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1085691 INFO (zkCallback-678-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2193131a name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1085691 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1085692 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1085693 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1085711 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1085733 INFO (zkCallback-679-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@41e7bc3 name:ZooKeeperConnection Watcher:127.0.0.1:49393 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1085733 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1085734 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1085734 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1085737 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1085738 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1085739 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1085740 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1085741 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1085742 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1085744 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1085745 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1085746 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@49bbb2e5 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1085746 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1085746 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1085747 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1085749 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 1085750 INFO (zkCallback-677-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1085755 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1085759 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1085766 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1085771 INFO (zkCallback-681-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@f9354f5 name:ZooKeeperConnection Watcher:127.0.0.1:49393/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1085771 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1085772 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1085772 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1085775 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1085776 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1085777 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1085777 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94782168560369668-127.0.0.1:49393_solr-n_0000000000 [junit4] 2> 1085778 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:49393_solr [junit4] 2> 1085778 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1085779 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168560369668-127.0.0.1:49393_solr-n_0000000000) starting [junit4] 2> 1085780 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1085781 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1085783 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1085784 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1085786 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1085787 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1085790 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1085791 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1085791 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1085794 INFO (OverseerCollectionConfigSetProcessor-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1085801 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"12", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 0 [junit4] 2> 1085802 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=12 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"12", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1085802 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1085802 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard9 [junit4] 2> 1085803 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1085803 INFO (zkCallback-681-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1085803 INFO (zkCallback-677-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1086301 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard9/election [junit4] 2> 1086302 INFO (zkCallback-677-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1086302 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1086302 INFO (zkCallback-681-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1086305 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard9/election/94782168560369667-node1_core1-n_0000000000 [junit4] 2> 1086306 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard9 [junit4] 2> 1086307 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1086310 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard9", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1086312 INFO (zkCallback-680-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1086313 INFO (zkCallback-677-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1087796 INFO (OverseerCollectionConfigSetProcessor-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:345) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.amILeader(OverseerTaskProcessor.java:355) [junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:172) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1087796 INFO (OverseerCollectionConfigSetProcessor-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor According to ZK I (id=94782168560369668-127.0.0.1:49393_solr-n_0000000000) am no longer a leader. [junit4] 2> 1087812 WARN (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.Overseer Solr cannot talk to ZK, exiting Overseer main queue loop [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-0000000001 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:244) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:241) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:241) [junit4] 2> at org.apache.solr.cloud.DistributedQueue.removeFirst(DistributedQueue.java:386) [junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:188) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:229) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1087812 INFO (OverseerStateUpdate-94782168560369668-127.0.0.1:49393_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:49393_solr [junit4] 2> 1087813 WARN (zkCallback-680-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1087813 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:345) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1087815 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49393 49393 [junit4] 2> 1088219 INFO (Thread-5963) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:49393 49393 [junit4] 2> 1088220 WARN (Thread-5963) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 3 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 3 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 3 /solr/live_nodes [junit4] 2> 3 /solr/collections [junit4] 2> [junit4] 2> 1088220 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testPlaceholders [junit4] 2> 1088221 INFO (TEST-OverseerTest.testPlaceholders-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168560369668-127.0.0.1:49393_solr-n_0000000000) closing [junit4] 2> 1088226 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testOverseerStatsReset [junit4] 2> 1088227 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1088227 INFO (Thread-5964) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1088227 INFO (Thread-5964) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1088327 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer start zk server on port:43586 [junit4] 2> 1088327 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1088328 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1088331 INFO (zkCallback-683-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7095b383 name:ZooKeeperConnection Watcher:127.0.0.1:43586 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1088331 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1088331 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1088332 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1088333 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1088334 INFO (zkCallback-684-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6aa23761 name:ZooKeeperConnection Watcher:127.0.0.1:43586 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1088334 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1088334 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1088334 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1088337 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1088337 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1088338 INFO (zkCallback-685-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@610c11bd name:ZooKeeperConnection Watcher:127.0.0.1:43586/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1088338 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1088338 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1088339 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1088340 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1088341 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1088342 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1088344 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1088344 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1088346 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1088346 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1088348 INFO (zkCallback-686-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@7d72c1eb name:ZooKeeperConnection Watcher:127.0.0.1:43586/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1088348 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1088348 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1088349 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1088351 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/node1 [junit4] 2> 1088353 INFO (zkCallback-686-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1088353 INFO (zkCallback-685-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1088353 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1088355 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1088357 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1088358 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1088359 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94782168736923650-127.0.0.1:43586_solr-n_0000000000 [junit4] 2> 1088359 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43586_solr [junit4] 2> 1088359 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1088361 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168736923650-127.0.0.1:43586_solr-n_0000000000) starting [junit4] 2> 1088362 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1088364 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1088365 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1088367 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1088369 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1088371 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1088374 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1088374 INFO (OverseerCollectionConfigSetProcessor-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1088375 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1088377 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} current state version: 0 [junit4] 2> 1088378 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"recovering", [junit4] 2> "node_name":"node1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"core_node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://node1/solr/"} [junit4] 2> 1088378 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1088378 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1088379 INFO (zkCallback-685-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1088379 INFO (zkCallback-686-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1088877 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1088879 INFO (zkCallback-686-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1088879 INFO (zkCallback-685-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1088883 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/94782168736923651-node1_core1-n_0000000000 [junit4] 2> 1088884 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1088886 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1088888 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168736923650-127.0.0.1:43586_solr-n_0000000000) closing [junit4] 2> 1088888 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ElectionContext Canceling election /overseer_elect/election/94782168736923650-127.0.0.1:43586_solr-n_0000000000 [junit4] 2> 1088888 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43586_solr [junit4] 2> 1088892 INFO (OverseerExitThread) [ ] o.a.s.c.Overseer I'm exiting , but I'm still the leader [junit4] 2> 1088892 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94782168736923650-127.0.0.1:43586_solr-n_0000000001 [junit4] 2> 1088893 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:43586_solr [junit4] 2> 1088893 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1088894 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168736923650-127.0.0.1:43586_solr-n_0000000001) starting [junit4] 2> 1088901 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1088902 INFO (OverseerCollectionConfigSetProcessor-94782168736923650-127.0.0.1:43586_solr-n_0000000001) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1088903 INFO (zkCallback-685-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1088903 INFO (zkCallback-686-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1088902 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000001) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1088905 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000001) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://node1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1088906 INFO (zkCallback-685-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1090403 WARN (zkCallback-686-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1090406 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43586 43586 [junit4] 2> 1090536 INFO (Thread-5964) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:43586 43586 [junit4] 2> 1090537 WARN (Thread-5964) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 2 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 2 /solr/clusterstate.json [junit4] 2> [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> 2 /solr/live_nodes [junit4] 2> 2 /solr/overseer/queue-work [junit4] 2> 2 /solr/collections [junit4] 2> [junit4] 2> 1090538 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testOverseerStatsReset [junit4] 2> 1090538 INFO (TEST-OverseerTest.testOverseerStatsReset-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168736923650-127.0.0.1:43586_solr-n_0000000001) closing [junit4] 2> 1090538 INFO (OverseerStateUpdate-94782168736923650-127.0.0.1:43586_solr-n_0000000001) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:43586_solr [junit4] 2> 1090546 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:345) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1090551 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBadQueueItem [junit4] 2> 1090552 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1090552 INFO (Thread-5965) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1090552 INFO (Thread-5965) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1090652 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer start zk server on port:56150 [junit4] 2> 1090652 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1090653 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1090656 INFO (zkCallback-688-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b96c990 name:ZooKeeperConnection Watcher:127.0.0.1:56150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1090656 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1090657 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1090658 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1090660 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1090660 INFO (zkCallback-689-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6e2aeb8a name:ZooKeeperConnection Watcher:127.0.0.1:56150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1090660 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1090661 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1090661 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1090664 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1090667 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1090668 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3c5f10e1 name:ZooKeeperConnection Watcher:127.0.0.1:56150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1090668 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1090668 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1090669 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1090670 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1090672 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1090673 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1090675 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1090676 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1090679 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1090680 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3114acd8 name:ZooKeeperConnection Watcher:127.0.0.1:56150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1090680 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1090680 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1090680 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1090682 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1090683 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1090685 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1090685 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94782168889294851-127.0.0.1:56150_solr-n_0000000000 [junit4] 2> 1090686 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:56150_solr [junit4] 2> 1090686 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1090687 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168889294851-127.0.0.1:56150_solr-n_0000000000) starting [junit4] 2> 1090689 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue [junit4] 2> 1090691 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1090693 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure [junit4] 2> 1090695 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running [junit4] 2> 1090698 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed [junit4] 2> 1090700 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work [junit4] 2> 1090704 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 1090705 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer Starting to work on the main queue [junit4] 2> 1090705 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1090707 INFO (OverseerCollectionConfigSetProcessor-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.OverseerTaskProcessor Process current queue of overseer operations [junit4] 2> 1090708 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1090710 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1090712 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1090713 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4e72054 name:ZooKeeperConnection Watcher:127.0.0.1:56150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1090713 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1090713 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1090715 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1090717 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1 [junit4] 2> 1090718 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1090718 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1090721 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 0) [junit4] 2> 1090724 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 0 [junit4] 2> 1090724 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1090724 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection1 [junit4] 2> 1090725 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1090726 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1090726 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1090727 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091223 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 1091225 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1091225 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1091225 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1091228 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard1/election/94782168889294852-127.0.0.1_core1-n_0000000000 [junit4] 2> 1091229 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard1 [junit4] 2> 1091231 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1091234 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1091236 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 1 [junit4] 2> 1091237 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1091237 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1091237 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 1091346 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091346 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091346 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091735 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 1091740 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard2/election/94782168889294852-127.0.0.1_core2-n_0000000000 [junit4] 2> 1091741 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard2 [junit4] 2> 1091743 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1091746 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core2", [junit4] 2> "state":"active"} current state version: 2 [junit4] 2> 1091748 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 2 [junit4] 2> 1091748 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1091748 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1091748 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 1091852 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091852 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1091853 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092247 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 1092252 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection1/leader_elect/shard3/election/94782168889294852-127.0.0.1_core3-n_0000000000 [junit4] 2> 1092252 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/leaders/shard3 [junit4] 2> 1092254 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1092257 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard3", [junit4] 2> "collection":"collection1", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core3", [junit4] 2> "state":"active"} current state version: 3 [junit4] 2> 1092360 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092360 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092361 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092410 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":"", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 4 [junit4] 2> 1092410 ERROR (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.CollectionMutator Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":"", [junit4] 2> "numShards":"1", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1092412 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"deletecore", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":""} current state version: 4 [junit4] 2> 1092412 ERROR (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.CollectionMutator Skipping invalid Overseer message because it has no collection specified: { [junit4] 2> "operation":"deletecore", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core0", [junit4] 2> "core_node_name":"node0", [junit4] 2> "collection":""} [junit4] 2> 1092414 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 4 [junit4] 2> 1092415 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core1", [junit4] 2> "core_node_name":"node1", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1092415 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ClusterStateMutator building a new cName: collection2 [junit4] 2> 1092415 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1092518 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092518 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092518 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1092913 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leader_elect/shard1/election [junit4] 2> 1092915 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1092915 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1092915 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections, has occurred - updating... [junit4] 2> 1092919 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection2/leader_elect/shard1/election/94782168889294852-127.0.0.1_core1-n_0000000000 [junit4] 2> 1092919 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leaders/shard1 [junit4] 2> 1092922 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1092925 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":"collection2", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core1", [junit4] 2> "state":"active"} current state version: 5 [junit4] 2> 1092927 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 5 [junit4] 2> 1092928 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core2", [junit4] 2> "core_node_name":"node2", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1092928 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1092928 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard2 [junit4] 2> 1093031 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093031 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093032 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093426 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leader_elect/shard2/election [junit4] 2> 1093429 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection2/leader_elect/shard2/election/94782168889294852-127.0.0.1_core2-n_0000000000 [junit4] 2> 1093430 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leaders/shard2 [junit4] 2> 1093432 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1093434 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard2", [junit4] 2> "collection":"collection2", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core2", [junit4] 2> "state":"active"} current state version: 6 [junit4] 2> 1093436 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} current state version: 6 [junit4] 2> 1093436 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core3", [junit4] 2> "core_node_name":"node3", [junit4] 2> "collection":"collection2", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 1093437 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Collection already exists with numShards=3 [junit4] 2> 1093437 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard3 [junit4] 2> 1093539 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093539 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093540 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1093934 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leader_elect/shard3/election [junit4] 2> 1093940 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /collections/collection2/leader_elect/shard3/election/94782168889294852-127.0.0.1_core3-n_0000000000 [junit4] 2> 1093941 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/collection2/leaders/shard3 [junit4] 2> 1093942 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node [junit4] 2> 1093945 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard3", [junit4] 2> "collection":"collection2", [junit4] 2> "base_url":"http://127.0.0.1/solr/", [junit4] 2> "core":"core3", [junit4] 2> "state":"active"} current state version: 7 [junit4] 2> 1094048 INFO (zkCallback-690-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1094048 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1094048 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 1094096 INFO (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1094096 INFO (zkCallback-691-thread-1) [ ] o.a.s.c.c.ZkStateReader A live node change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1) [junit4] 2> 1095597 WARN (zkCallback-693-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK [junit4] 2> 1095600 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:56150 56150 [junit4] 2> 1095836 INFO (Thread-5965) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:56150 56150 [junit4] 2> 1095838 WARN (Thread-5965) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 3 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 3 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 3 /solr/live_nodes [junit4] 2> 3 /solr/collections [junit4] 2> [junit4] 2> 1095838 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testBadQueueItem [junit4] 2> 1095838 INFO (TEST-OverseerTest.testBadQueueItem-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782168889294851-127.0.0.1:56150_solr-n_0000000000) closing [junit4] 2> 1095838 INFO (OverseerStateUpdate-94782168889294851-127.0.0.1:56150_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:56150_solr [junit4] 2> 1095841 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:345) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1095846 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testReplay [junit4] 2> 1095847 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 1095847 INFO (Thread-5966) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 1095847 INFO (Thread-5966) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 1095947 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer start zk server on port:35708 [junit4] 2> 1095947 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1095948 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1095952 INFO (zkCallback-694-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@289a40bd name:ZooKeeperConnection Watcher:127.0.0.1:35708/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1095952 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1095952 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1095953 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1095953 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1095954 INFO (zkCallback-695-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@754ef4ed name:ZooKeeperConnection Watcher:127.0.0.1:35708 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1095954 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1095955 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1095956 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1095959 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1095960 INFO (zkCallback-696-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@31fa4ace name:ZooKeeperConnection Watcher:127.0.0.1:35708 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1095960 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1095960 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1095960 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr [junit4] 2> 1095964 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes [junit4] 2> 1095965 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections [junit4] 2> 1095967 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json [junit4] 2> 1095968 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json [junit4] 2> 1095970 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json [junit4] 2> 1095971 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... [junit4] 2> 1095974 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work [junit4] 2> 1095976 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider [junit4] 2> 1095977 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper [junit4] 2> 1095978 INFO (zkCallback-697-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@1b622fd5 name:ZooKeeperConnection Watcher:127.0.0.1:35708/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 1095978 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper [junit4] 2> 1095979 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider [junit4] 2> 1095979 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true [junit4] 2> 1095980 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect [junit4] 2> 1095982 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election [junit4] 2> 1095983 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 1095984 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94782169236373507-127.0.0.1:35708_solr-n_0000000000 [junit4] 2> 1095984 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35708_solr [junit4] 2> 1095984 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader [junit4] 2> 1095986 INFO (TEST-OverseerTest.testReplay-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782169236373507-127.0.0.1:35708_solr-n_000000000 [...truncated too long message...] 00000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} current state version: 0 [junit4] 2> 1146269 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"recovering"} [junit4] 2> 1146269 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1 [junit4] 2> 1146273 INFO (zkCallback-793-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1146273 INFO (zkCallback-796-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1146315 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} current state version: 1 [junit4] 2> 1146316 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator Update state numShards=null message={ [junit4] 2> "operation":"state", [junit4] 2> "base_url":"http://127.0.0.1/solr", [junit4] 2> "node_name":"node1", [junit4] 2> "collection":"collection1", [junit4] 2> "core":"core1", [junit4] 2> "roles":"", [junit4] 2> "state":"active"} [junit4] 2> 1146316 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator node=core_node1 is already registered [junit4] 2> 1146316 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.o.ReplicaMutator shard=shard1 is already registered [junit4] 2> 1146419 INFO (zkCallback-793-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1146419 INFO (zkCallback-796-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0) [junit4] 2> 1146467 INFO (TEST-OverseerTest.testStateChange-seed#[51C979EA21C2E92]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59284 59284 [junit4] 2> 1146684 INFO (Thread-5974) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:59284 59284 [junit4] 2> 1146685 WARN (Thread-5974) [ ] o.a.s.c.ZkTestServer Watch limit violations: [junit4] 2> Maximum concurrent create/delete watches above limit: [junit4] 2> [junit4] 2> 2 /solr/aliases.json [junit4] 2> [junit4] 2> Maximum concurrent data watches above limit: [junit4] 2> [junit4] 2> 2 /solr/clusterstate.json [junit4] 2> [junit4] 2> Maximum concurrent children watches above limit: [junit4] 2> [junit4] 2> 2 /solr/live_nodes [junit4] 2> 2 /solr/collections [junit4] 2> [junit4] 2> 1146685 INFO (TEST-OverseerTest.testStateChange-seed#[51C979EA21C2E92]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateChange [junit4] 2> 1146685 INFO (TEST-OverseerTest.testStateChange-seed#[51C979EA21C2E92]) [ ] o.a.s.c.Overseer Overseer (id=94782172528771075-127.0.0.1:59284_solr-n_0000000000) closing [junit4] 2> 1146685 INFO (OverseerStateUpdate-94782172528771075-127.0.0.1:59284_solr-n_0000000000) [ ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:59284_solr [junit4] 2> 1146686 ERROR (OverseerExitThread) [ ] o.a.s.c.Overseer could not read the data [junit4] 2> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:345) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:342) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:87) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$2.run(Overseer.java:265) [junit4] 2> 1149687 INFO (SUITE-OverseerTest-seed#[51C979EA21C2E92]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerTest_51C979EA21C2E92-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {}, docValues:{}, sim=DefaultSimilarity, locale=ar_LB, timezone=America/El_Salvador [junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.7.0_72 (64-bit)/cpus=4,threads=1,free=282130512,total=505937920 [junit4] 2> NOTE: All tests run in this JVM: [TestTolerantSearch, TestStressUserVersions, TestFieldResource, SynonymTokenizerTest, TestManagedSchemaFieldResource, TestExclusionRuleCollectionAccess, TestUniqueKeyFieldResource, HdfsUnloadDistributedZkTest, LeaderElectionIntegrationTest, TestCloudManagedSchema, AnalysisAfterCoreReloadTest, ZkStateReaderTest, DistributedMLTComponentTest, RequiredFieldsTest, TestManagedResource, DisMaxRequestHandlerTest, TestCSVLoader, TestValueSourceCache, CollectionReloadTest, TestAuthorizationFramework, TestMergePolicyConfig, BasicDistributedZkTest, TestRealTimeGet, TestRandomFaceting, PingRequestHandlerTest, BasicAuthIntegrationTest, TestSchemaSimilarityResource, ParsingFieldUpdateProcessorsTest, TestClassNameShortening, TestAnalyzedSuggestions, AnalysisErrorHandlingTest, EchoParamsTest, JSONWriterTest, StressHdfsTest, TestMinMaxOnMultiValuedField, BitVectorTest, AlternateDirectoryTest, TestRangeQuery, TestFoldingMultitermQuery, TestRawTransformer, TestRecoveryHdfs, TestSolrConfigHandler, DateFieldTest, ExitableDirectoryReaderTest, TimeZoneUtilsTest, TestCustomSort, TestSearcherReuse, TestCloudSchemaless, ResponseHeaderTest, TestConfig, TestDistributedMissingSort, TestIBSimilarityFactory, PeerSyncTest, SolrRequestParserTest, TestDistributedStatsComponentCardinality, QueryEqualityTest, HdfsChaosMonkeyNothingIsSafeTest, HighlighterMaxOffsetTest, TestFaceting, OpenExchangeRatesOrgProviderTest, OutputWriterTest, QueryElevationComponentTest, TestJoin, TestManagedSynonymFilterFactory, TestManagedStopFilterFactory, TestArbitraryIndexDir, XsltUpdateRequestHandlerTest, FullHLLTest, OverriddenZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZk2Test, TestHighFrequencyDictionaryFactory, StandardRequestHandlerTest, JsonLoaderTest, HLLUtilTest, TestCursorMarkWithoutUniqueKey, DistribJoinFromCollectionTest, BadCopyFieldTest, SOLR749Test, TestBinaryField, ReturnFieldsTest, TestLuceneMatchVersion, DistributedQueueTest, TestSolr4Spatial, TestSolrJ, AsyncMigrateRouteKeyTest, CloudExitableDirectoryReaderTest, DeleteShardTest, TestReqParamsAPI, TestRemoteStreaming, TestPseudoReturnFields, SyncSliceTest, OverseerTest] [junit4] Completed [274/543] on J0 in 64.19s, 12 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 840 lines...] BUILD FAILED /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:785: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:729: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/build.xml:59: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/build.xml:233: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/solr/common-build.xml:526: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1452: The following error occurred while executing this line: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.x-Java7/lucene/common-build.xml:1006: There were test failures: 543 suites (7 ignored), 2147 tests, 1 failure, 50 ignored (37 assumptions) [seed: 51C979EA21C2E92] Total time: 56 minutes 58 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Recording test results Email was triggered for: Failure - Any Sending email for trigger: Failure - Any
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org