Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/609/
2 tests failed. FAILED: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch Error Message: Error executing query Stack Trace: org.apache.solr.client.solrj.SolrServerException: Error executing query at __randomizedtesting.SeedInfo.seed([6C04E215DCCDAF01:EDE26C0DAB92CF3D]:0) at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:100) at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301) at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:223) at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:165) at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:414) at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:144) at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869) 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:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) 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:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) 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:43) 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:365) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.http.ParseException: Invalid content type: at org.apache.http.entity.ContentType.parse(ContentType.java:233) at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:496) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210) at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206) at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91) ... 46 more FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure Error Message: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed Stack Trace: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed at __randomizedtesting.SeedInfo.seed([6C04E215DCCDAF01:680C6DE6CE684020]:0) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) 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:1618) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) 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:365) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) 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:43) 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:365) at java.lang.Thread.run(Thread.java:745) Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403) at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142) at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31) at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137) ... 47 more Build Log: [...truncated 11818 lines...] [junit4] Suite: org.apache.solr.cloud.OverseerTest [junit4] 2> Creating dataDir: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-6C04E215DCCDAF01-001/init-core-data-001 [junit4] 2> 2626706 T7707 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true) [junit4] 2> 2626706 T7707 oas.SolrTestCaseJ4.initCore ####initCore [junit4] 2> 2626706 T7707 oas.SolrTestCaseJ4.initCore ####initCore end [junit4] 2> 2626711 T7707 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem [junit4] 2> 2626712 T7707 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2626713 T7708 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 2626813 T7707 oasc.ZkTestServer.run start zk server on port:14319 [junit4] 2> 2626815 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2626818 T7714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b0edc0a name:ZooKeeperConnection Watcher:127.0.0.1:14319 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2626819 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2626821 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2626822 T7716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@744f6fd0 name:ZooKeeperConnection Watcher:127.0.0.1:14319 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2626823 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2626823 T7707 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 2626827 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2626828 T7718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a39c0ab name:ZooKeeperConnection Watcher:127.0.0.1:14319/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2626828 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2626829 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 2626831 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2626832 T7720 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22c00c9e name:ZooKeeperConnection Watcher:127.0.0.1:14319/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2626833 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2626833 T7707 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 2626834 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 2626836 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 2626838 T7707 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2626839 T7707 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:14319_solr [junit4] 2> 2626839 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2626841 T7707 oasc.Overseer.start Overseer (id=92326438061932547-127.0.0.1:14319_solr-n_0000000000) starting [junit4] 2> 2626842 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 2626844 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 2626846 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 2626849 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 2626851 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 2626853 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 2626856 T7707 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2626857 T7722 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2626858 T7707 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 2626858 T7721 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2626859 T7707 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 2626861 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2626863 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2626865 T7725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c93d398 name:ZooKeeperConnection Watcher:127.0.0.1:14319/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2626865 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2626867 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2626868 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1 [junit4] 2> 2626872 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2626874 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2626874 T7721 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3] [junit4] 2> 2626875 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2626877 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2626877 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2627373 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2627379 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2627382 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2627386 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2627386 T7721 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2627386 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 2627388 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2627389 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2627389 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2627884 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 2627889 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3 [junit4] 2> 2627893 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2627896 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2627896 T7721 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2627896 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 2627898 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2627899 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2627899 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2628394 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 2628399 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 2628402 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2628506 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2628506 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2628556 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2628558 T7721 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR 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> 2628561 T7721 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR 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> 2628562 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2628563 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2628563 T7721 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3] [junit4] 2> 2628564 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2628666 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2628666 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2629059 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election [junit4] 2> 2629065 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1 [junit4] 2> 2629069 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2629072 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2629073 T7721 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2629073 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 2629075 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2629075 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2629075 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2629570 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election [junit4] 2> 2629575 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3 [junit4] 2> 2629578 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2629582 T7721 oasc.Overseer$ClusterStateUpdater.updateState 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> 2629582 T7721 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2629582 T7721 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 2629584 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2629585 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2629585 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2630080 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election [junit4] 2> 2630085 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2 [junit4] 2> 2630088 T7728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2630193 T7726 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2630193 T7727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2630247 T7707 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:14319 14319 [junit4] 2> 2630407 T7708 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:14319 14319 [junit4] 2> 2630408 T7707 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem [junit4] 2> 2630409 T7707 oasc.Overseer.close Overseer (id=92326438061932547-127.0.0.1:14319_solr-n_0000000000) closing [junit4] 2> 2630409 T7721 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:14319_solr [junit4] 2> 2630411 T7729 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293) [junit4] 2> [junit4] 2> 2630417 T7707 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure [junit4] 2> 2630418 T7707 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2630419 T7730 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 2630518 T7707 oasc.ZkTestServer.run start zk server on port:22106 [junit4] 2> 2630520 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2630523 T7736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51828fc5 name:ZooKeeperConnection Watcher:127.0.0.1:22106 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2630524 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2630526 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2630527 T7738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16b9338f name:ZooKeeperConnection Watcher:127.0.0.1:22106 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2630528 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2630528 T7707 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 2630532 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2630534 T7740 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59fd6512 name:ZooKeeperConnection Watcher:127.0.0.1:22106/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2630534 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2630534 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 2630536 T7707 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 2630538 T7707 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 2630539 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2630541 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2630542 T7742 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c48c6fc name:ZooKeeperConnection Watcher:127.0.0.1:22106/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2630542 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2630544 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2630545 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 2630548 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2630549 T7746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1884bae7 name:ZooKeeperConnection Watcher:127.0.0.1:22106/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2630549 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2630550 T7707 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 2630551 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 2630552 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 2630554 T7707 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2630556 T7707 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:22106_solr [junit4] 2> 2630556 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2630557 T7707 oasc.Overseer.start Overseer (id=92326438304808964-127.0.0.1:22106_solr-n_0000000000) starting [junit4] 2> 2630559 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 2630561 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 2630563 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 2630565 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 2630567 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 2630570 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 2630573 T7707 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2630574 T7748 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2630575 T7747 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2631576 T7750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2631578 T7747 oasc.Overseer$ClusterStateUpdater.updateState 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> 2631578 T7747 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 2631579 T7747 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2631581 T7743 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2631581 T7744 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2632076 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2632082 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2632086 T7750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2632088 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2632090 T7747 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [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> 2632090 T7747 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 2632092 T7750 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2632092 T7744 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2632092 T7743 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2632577 T7748 oasc.OverseerCollectionProcessor.amILeader 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:513) [junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:271) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 2632577 T7748 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92326438304808964-127.0.0.1:22106_solr-n_0000000000) am no longer a leader. [junit4] 2> 2633147 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2633152 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2633153 T7752 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f881244 name:ZooKeeperConnection Watcher:127.0.0.1:22106/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2633153 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2633154 T7707 oasc.Overseer.close Overseer (id=92326438304808964-127.0.0.1:22106_solr-n_0000000000) closing [junit4] 2> 2633154 T7747 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:22106_solr [junit4] 2> 2633155 T7707 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 2633156 T7753 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293) [junit4] 2> [junit4] 2> 2633158 T7707 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2633159 T7707 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:22106_solr [junit4] 2> 2633160 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2633161 T7707 oasc.Overseer.start Overseer (id=92326438304808965-127.0.0.1:22106_solr-n_0000000001) starting [junit4] 2> 2633168 T7707 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2633168 T7755 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2633169 T7754 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2633171 T7754 oasc.Overseer$ClusterStateUpdater.updateState 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> 2633171 T7754 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 2633173 T7757 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2633174 T7743 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2633174 T7744 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2633226 T7757 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2633226 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2633230 T7707 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92326438304808963-node1_core1-n_0000000002 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111) [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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) [junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772) [junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53) [junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46) [junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43) [junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65) [junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55) [junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) [junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 2633233 T7758 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2633233 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2633232 T7754 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125) [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:189) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:186) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:186) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:670) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:665) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1098) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:363) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:246) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> [junit4] 2> 2633234 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2633236 T7757 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2633237 T7754 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1 [junit4] 2> 2633340 T7744 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2633340 T7758 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2634236 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2634237 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2635238 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2635239 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2636241 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2636242 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2637244 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2637244 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2638247 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2638247 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2639250 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2639251 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2640253 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2640253 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2641256 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2641257 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2642259 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2642259 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2643262 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2643263 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2644265 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2644265 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2645268 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2645268 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2646271 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2646271 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2647274 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2647274 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2648277 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2648277 T7743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2648280 T7743 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150) [junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) [junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) [junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55) [junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:209) [junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) [junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:262) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) [junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) [junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] 2> at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142) [junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31) [junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137) [junit4] 2> ... 10 more [junit4] 2> [junit4] 2> 2648285 T7707 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:22106 22106 [junit4] 2> 2648367 T7730 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:22106 22106 [junit4] 2> 2648368 T7707 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure [junit4] 2> 2648369 T7707 oasc.Overseer.close Overseer (id=92326438304808965-127.0.0.1:22106_solr-n_0000000001) closing [junit4] 2> 2648369 T7754 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:22106_solr [junit4] 2> 2648371 T7759 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293) [junit4] 2> [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=6C04E215DCCDAF01 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=sr_ME_#Latn -Dtests.timezone=Asia/Shanghai -Dtests.file.encoding=UTF-8 [junit4] ERROR 18.0s J0 | OverseerTest.testOverseerFailure <<< [junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed [junit4] > at __randomizedtesting.SeedInfo.seed([6C04E215DCCDAF01:680C6DE6CE684020]:0) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150) [junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125) [junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314) [junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221) [junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157) [junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1 [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119) [junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51) [junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783) [junit4] > at org.apache.solr.common.cloud.SolrZkClient$11.execute(SolrZkClient.java:462) [junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:459) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:416) [junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:403) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142) [junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31) [junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137) [junit4] > ... 47 more [junit4] 2> 2648398 T7707 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment [junit4] 2> 2648399 T7707 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2648400 T7760 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 2648500 T7707 oasc.ZkTestServer.run start zk server on port:49922 [junit4] 2> 2648502 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2648506 T7766 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@310c662f name:ZooKeeperConnection Watcher:127.0.0.1:49922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2648506 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2648507 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2648508 T7768 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55e1fba0 name:ZooKeeperConnection Watcher:127.0.0.1:49922 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2648508 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2648511 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2648512 T7770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bc47283 name:ZooKeeperConnection Watcher:127.0.0.1:49922 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2648512 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2648512 T7707 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 2648515 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 2648517 T7707 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 2648519 T7707 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 2648520 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2648522 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2648523 T7772 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fa3ad8e name:ZooKeeperConnection Watcher:127.0.0.1:49922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2648524 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2648525 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2648526 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 2648529 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2648530 T7776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31548727 name:ZooKeeperConnection Watcher:127.0.0.1:49922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2648531 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2648531 T7707 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 2648532 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 2648534 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 2648535 T7707 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2648537 T7707 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49922_solr [junit4] 2> 2648537 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2648538 T7707 oasc.Overseer.start Overseer (id=92326439483211780-127.0.0.1:49922_solr-n_0000000000) starting [junit4] 2> 2648540 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 2648542 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 2648544 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 2648546 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 2648548 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 2648550 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 2648553 T7707 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2648554 T7778 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2648555 T7777 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2648557 T7777 oasc.Overseer$ClusterStateUpdater.updateState 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> 2648557 T7777 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1] [junit4] 2> 2648557 T7777 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2648559 T7780 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2648559 T7773 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2648559 T7774 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649056 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2649062 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2649066 T7780 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649070 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649071 T7782 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@608dac43 name:ZooKeeperConnection Watcher:127.0.0.1:49922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649071 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649073 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2649074 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes/node1 [junit4] 2> 2649078 T7780 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649078 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2649078 T7777 oasc.Overseer$ClusterStateUpdater.updateState 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> 2649078 T7777 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered [junit4] 2> 2649081 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2649084 T7780 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649188 T7783 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649188 T7774 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649194 T7707 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49922 49922 [junit4] 2> 2649290 T7760 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49922 49922 [junit4] 2> 2649292 T7707 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment [junit4] 2> 2649292 T7707 oasc.Overseer.close Overseer (id=92326439483211780-127.0.0.1:49922_solr-n_0000000000) closing [junit4] 2> 2649292 T7777 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49922_solr [junit4] 2> 2649295 T7784 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data 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$8.execute(SolrZkClient.java:307) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74) [junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:304) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89) [junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293) [junit4] 2> [junit4] 2> 2649300 T7707 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment [junit4] 2> 2649302 T7707 oasc.ZkTestServer.run STARTING ZK TEST SERVER [junit4] 1> client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2649302 T7785 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server [junit4] 2> 2649402 T7707 oasc.ZkTestServer.run start zk server on port:53240 [junit4] 2> 2649404 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649407 T7791 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@65abfe78 name:ZooKeeperConnection Watcher:127.0.0.1:53240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649408 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649410 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649411 T7793 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5263d9 name:ZooKeeperConnection Watcher:127.0.0.1:53240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649412 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649412 T7707 oascc.SolrZkClient.makePath makePath: /solr [junit4] 2> 2649416 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649417 T7795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c0e22f0 name:ZooKeeperConnection Watcher:127.0.0.1:53240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649417 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649418 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes [junit4] 2> 2649420 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649421 T7797 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4cfc017b name:ZooKeeperConnection Watcher:127.0.0.1:53240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649421 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649422 T7707 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false [junit4] 2> 2649423 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect [junit4] 2> 2649424 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/election [junit4] 2> 2649426 T7707 oasc.Overseer.close Overseer (id=null) closing [junit4] 2> 2649427 T7707 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53240_solr [junit4] 2> 2649427 T7707 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader [junit4] 2> 2649429 T7707 oasc.Overseer.start Overseer (id=92326439542390787-127.0.0.1:53240_solr-n_0000000000) starting [junit4] 2> 2649430 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue [junit4] 2> 2649433 T7707 oascc.SolrZkClient.makePath makePath: /overseer/queue-work [junit4] 2> 2649435 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure [junit4] 2> 2649437 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running [junit4] 2> 2649439 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed [junit4] 2> 2649441 T7707 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work [junit4] 2> 2649445 T7707 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000 [junit4] 2> 2649446 T7799 oasc.OverseerCollectionProcessor.run Process current queue of collection creations [junit4] 2> 2649446 T7707 oascc.SolrZkClient.makePath makePath: /clusterstate.json [junit4] 2> 2649447 T7798 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue [junit4] 2> 2649448 T7707 oascc.SolrZkClient.makePath makePath: /aliases.json [junit4] 2> 2649449 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2649451 T7707 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper [junit4] 2> 2649453 T7802 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f66eda4 name:ZooKeeperConnection Watcher:127.0.0.1:53240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None [junit4] 2> 2649453 T7707 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper [junit4] 2> 2649454 T7707 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... [junit4] 2> 2649456 T7707 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1 [junit4] 2> 2649460 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649461 T7798 oasc.Overseer$ClusterStateUpdater.updateState 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> 2649461 T7798 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3] [junit4] 2> 2649462 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2649464 T7804 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649464 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649960 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2649967 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1 [junit4] 2> 2649970 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649974 T7798 oasc.Overseer$ClusterStateUpdater.updateState 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> 2649974 T7798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2649974 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 2649976 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2649976 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2649976 T7804 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2650471 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 2650476 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3 [junit4] 2> 2650480 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2650483 T7798 oasc.Overseer$ClusterStateUpdater.updateState 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> 2650483 T7798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2650483 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 2650485 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2650486 T7804 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2650486 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2650981 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election [junit4] 2> 2650986 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2 [junit4] 2> 2650989 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2650992 T7798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core4", [junit4] 2> "core_node_name":"node4", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 2650993 T7798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2650993 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1 [junit4] 2> 2650999 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2651001 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2651001 T7804 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2651490 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election [junit4] 2> 2651496 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2651497 T7798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core5", [junit4] 2> "core_node_name":"node5", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 2651498 T7798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2651498 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3 [junit4] 2> 2651601 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2651601 T7804 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2651996 T7707 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election [junit4] 2> 2652002 T7805 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged [junit4] 2> 2652003 T7798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={ [junit4] 2> "operation":"state", [junit4] 2> "state":"active", [junit4] 2> "node_name":"127.0.0.1", [junit4] 2> "core":"core6", [junit4] 2> "core_node_name":"node6", [junit4] 2> "collection":"collection1", [junit4] 2> "numShards":"3", [junit4] 2> "base_url":"http://127.0.0.1/solr/"} [junit4] 2> 2652004 T7798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3 [junit4] 2> 2652004 T7798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2 [junit4] 2> 2652107 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1) [junit4] 2> 2652107 T7804 oascc.ZkStateReader$2.process A cluster state ch [...truncated too long message...] t_t=PostingsFormat(name=Memory doPackFST= false), 11grand5_s=PostingsFormat(name=SimpleText), 4child2_s=PostingsFormat(name=Memory doPackFST= false), 5child3_s=PostingsFormat(name=MockRandom), 38parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 34parent_f2_s=PostingsFormat(name=MockRandom), 3parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 2parent_f1_s=PostingsFormat(name=Memory doPackFST= false), _root_=PostingsFormat(name=Memory doPackFST= false), 39parent_f1_s=PostingsFormat(name=Memory doPackFST= false), 6child0_s=PostingsFormat(name=Memory doPackFST= false), 4child0_s=PostingsFormat(name=MockRandom), 6child1_s=PostingsFormat(name=SimpleText), 22parent_f1_s=PostingsFormat(name=MockRandom), 0parent_f1_s=PostingsFormat(name=MockRandom), 36parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 29parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 11parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 5child4_s=PostingsFormat(name=SimpleText), 3parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 12parent_f2_s=PostingsFormat(name=MockRandom), 6grand5_s=PostingsFormat(name=Lucene41WithOrds), 7parent_f1_s=PostingsFormat(name=Lucene41WithOrds), type_s=PostingsFormat(name=Memory doPackFST= false), 1child0_s=PostingsFormat(name=Lucene41WithOrds), 4parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 8grand0_s=PostingsFormat(name=MockRandom), 11grand3_s=PostingsFormat(name=Lucene41WithOrds), 24parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 10grand7_s=PostingsFormat(name=Memory doPackFST= false), 30parent_f2_s=PostingsFormat(name=MockRandom), 9grand4_s=PostingsFormat(name=SimpleText), 41parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 10grand0_s=PostingsFormat(name=SimpleText), 7grand1_s=PostingsFormat(name=MockRandom), 10parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 2grand0_s=PostingsFormat(name=Memory doPackFST= false), 37parent_f1_s=PostingsFormat(name=MockRandom), 1parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 22parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 16parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 8grand2_s=PostingsFormat(name=Memory doPackFST= false), 2grand1_s=PostingsFormat(name=Lucene41WithOrds), 31parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 9grand8_s=PostingsFormat(name=SimpleText), 5parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 17parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 37parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 23parent_f2_s=PostingsFormat(name=MockRandom), 30parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 9grand1_s=PostingsFormat(name=Memory doPackFST= false), 28parent_f1_s=PostingsFormat(name=Memory doPackFST= false), 7grand6_s=PostingsFormat(name=Lucene41WithOrds), 6grand0_s=PostingsFormat(name=Memory doPackFST= false), 32parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 26parent_f1_s=PostingsFormat(name=MockRandom), 25parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 4parent_f1_s=PostingsFormat(name=MockRandom), 6child5_s=PostingsFormat(name=SimpleText), 5child0_s=PostingsFormat(name=SimpleText), 5grand0_s=PostingsFormat(name=Lucene41WithOrds), 13parent_f1_s=PostingsFormat(name=Memory doPackFST= false), 8grand7_s=PostingsFormat(name=Lucene41WithOrds), 17parent_f1_s=PostingsFormat(name=Memory doPackFST= false), 2child0_s=PostingsFormat(name=Memory doPackFST= false), 1parent_f2_s=PostingsFormat(name=MockRandom), 5grand1_s=PostingsFormat(name=Memory doPackFST= false), 13parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 21parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 11grand2_s=PostingsFormat(name=Memory doPackFST= false), 12parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 35parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 18parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 29parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 21parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 8grand1_s=PostingsFormat(name=Lucene41WithOrds), 11grand0_s=PostingsFormat(name=MockRandom), 33parent_f1_s=PostingsFormat(name=MockRandom), 8parent_f1_s=PostingsFormat(name=MockRandom), 40parent_f1_s=PostingsFormat(name=MockRandom), 5grand2_s=PostingsFormat(name=SimpleText), 33parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 7grand5_s=PostingsFormat(name=MockRandom), 10grand6_s=PostingsFormat(name=Lucene41WithOrds), 6child4_s=PostingsFormat(name=Memory doPackFST= false), 9grand0_s=PostingsFormat(name=SimpleText), 10grand1_s=PostingsFormat(name=MockRandom), 0parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 7grand2_s=PostingsFormat(name=Lucene41WithOrds), 5parent_f2_s=PostingsFormat(name=MockRandom), 5grand4_s=PostingsFormat(name=Lucene41WithOrds), 4child3_s=PostingsFormat(name=SimpleText), 6grand1_s=PostingsFormat(name=Lucene41WithOrds), 10grand3_s=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=Memory doPackFST= false), 4grand2_s=PostingsFormat(name=Memory doPackFST= false), 4grand3_s=PostingsFormat(name=Lucene41WithOrds), 8grand5_s=PostingsFormat(name=Lucene41WithOrds), 15parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 4grand0_s=PostingsFormat(name=MockRandom), 26parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 18parent_f2_s=PostingsFormat(name=Memory doPackFST= false), 14parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 3child1_s=PostingsFormat(name=MockRandom), 7grand0_s=PostingsFormat(name=Lucene41WithOrds), 2child1_s=PostingsFormat(name=Lucene41WithOrds), 7grand4_s=PostingsFormat(name=Lucene41WithOrds), 9grand7_s=PostingsFormat(name=MockRandom)}, docValues:{}, sim=DefaultSimilarity, locale=uk_UA, timezone=Pacific/Gambier [junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=199808304,total=477102080 [junit4] 2> NOTE: All tests run in this JVM: [LegacyHTMLStripCharFilterTest, TestRealTimeGet, ShardSplitTest, QueryElevationComponentTest, TestRecovery, HdfsCollectionsAPIDistributedZkTest, TestIndexingPerformance, SortByFunctionTest, FieldFacetTest, TestHighlightDedupGrouping, UpdateRequestProcessorFactoryTest, HdfsSyncSliceTest, TestUtils, AssignTest, TestZkChroot, FunctionTest, ScriptEngineTest, TestImplicitCoreProperties, OutputWriterTest, ChangedSchemaMergeTest, DistributedFacetPivotLargeTest, TestIntervalFaceting, TestFileDictionaryLookup, TestCopyFieldCollectionResource, TestNoOpRegenerator, TestGroupingSearch, OverseerRolesTest, SearchHandlerTest, TestClassNameShortening, CoreMergeIndexesAdminHandlerTest, TestAtomicUpdateErrorCases, CopyFieldTest, UniqFieldsUpdateProcessorFactoryTest, TestOverriddenPrefixQueryForCustomFieldType, TestOrdValues, TestCustomSort, SolrPluginUtilsTest, DocValuesTest, CSVRequestHandlerTest, CollectionsAPIDistributedZkTest, TestUniqueKeyFieldResource, TestPHPSerializedResponseWriter, TestManagedResource, CacheHeaderTest, TestCoreContainer, TestReversedWildcardFilterFactory, MultiThreadedOCPTest, TestCollapseQParserPlugin, TestSolrQueryParserResource, AliasIntegrationTest, TestCSVLoader, TestInfoStreamLogging, DebugComponentTest, FileBasedSpellCheckerTest, TestRequestStatusCollectionAPI, TestQueryTypes, CircularListTest, PolyFieldTest, SolrIndexConfigTest, TestJmxMonitoredMap, SampleTest, TestJoin, AddSchemaFieldsUpdateProcessorFactoryTest, TestSolrQueryParserDefaultOperatorResource, TestIBSimilarityFactory, PreAnalyzedFieldTest, TestDistribDocBasedVersion, RAMDirectoryFactoryTest, LukeRequestHandlerTest, TestExceedMaxTermLength, TestPerFieldSimilarity, SuggestComponentTest, ZkSolrClientTest, CustomCollectionTest, TestCollationFieldDocValues, NumericFieldsTest, CursorMarkTest, TestDistributedGrouping, SolrXmlInZkTest, TestNonDefinedSimilarityFactory, ShardRoutingCustomTest, SolrRequestParserTest, TestCSVResponseWriter, SoftAutoCommitTest, ExpressionTest, TestWriterPerf, SimplePostToolTest, TestManagedResourceStorage, BinaryUpdateRequestHandlerTest, DirectSolrConnectionTest, TestPostingsSolrHighlighter, TestLFUCache, BasicDistributedZk2Test, RequestHandlersTest, TestSweetSpotSimilarityFactory, DistributedFacetPivotLongTailTest, TestCollectionAPI, HdfsBasicDistributedZk2Test, TestCharFilters, TestOmitPositions, TestSolrXmlPersistence, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, BasicZkTest, FullSolrCloudDistribCmdsTest] [junit4] Completed on J1 in 162.27s, 1 test, 1 error <<< FAILURES! [...truncated 666 lines...] BUILD FAILED /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:492: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:465: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:48: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/extra-targets.xml:37: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:189: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:494: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1342: The following error occurred while executing this line: /usr/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:957: There were test failures: 430 suites, 1783 tests, 2 errors, 52 ignored (9 assumptions) Total time: 249 minutes 14 seconds Build step 'Invoke Ant' marked build as failure Archiving artifacts Sending artifact delta relative to Lucene-Solr-NightlyTests-trunk #605 Archived 3 artifacts Archive block size is 32768 Received 0 blocks and 669074040 bytes Compression is 0.0% Took 1 min 57 sec Recording test results Email was triggered for: Failure Sending email for trigger: Failure
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org