You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/01/08 04:36:07 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.6.0_45) - Build #
3574 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3574/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([6FB50D224E2B0925:6BBD82D15C8EE604]:0)
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$10.execute(SolrZkClient.java:428)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
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:70)
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:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
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 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:70)
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:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9706 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 1509163 T4266 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-OverseerTest-1389150416692
[junit4] 2> 1509167 T4266 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1509171 T4266 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1509171 T4266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1509172 T4267 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1509270 T4266 oasc.ZkTestServer.run start zk server on port:55204
[junit4] 2> 1509274 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1509288 T4273 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3adfaf30 name:ZooKeeperConnection Watcher:127.0.0.1:55204/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1509288 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1509291 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1509299 T4275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75cbd6e1 name:ZooKeeperConnection Watcher:127.0.0.1:55204 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1509300 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1509307 T4268 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1436fd12f450001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1509310 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1509317 T4277 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e644cbb name:ZooKeeperConnection Watcher:127.0.0.1:55204 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1509318 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1509318 T4266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1509343 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1509351 T4266 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1509357 T4266 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1509363 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1509373 T4266 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1509384 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1509387 T4279 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24597553 name:ZooKeeperConnection Watcher:127.0.0.1:55204/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1509388 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1509390 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1509411 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1509426 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1509442 T4266 oasc.Overseer.start Overseer (id=91039361709441027-127.0.0.1:55204_solr-n_0000000000) starting
[junit4] 2> 1509442 T4266 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1509457 T4266 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1509457 T4281 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1509472 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1509472 T4280 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1509472 T4280 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1509472 T4273 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1509488 T4280 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1509488 T4273 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1509503 T4280 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1509503 T4280 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1509503 T4280 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1509518 T4279 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1509518 T4273 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1509579 T4266 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55204 55204
[junit4] 2> 1511785 T4268 oazs.NIOServerCnxnFactory.run WARN Ignoring exception java.nio.channels.ClosedChannelException
[junit4] 2> at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:135)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:188)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1511785 T4266 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1511785 T4266 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 1511785 T4266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1511785 T4282 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1511892 T4266 oasc.ZkTestServer.run start zk server on port:55219
[junit4] 2> 1511892 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1511892 T4288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c7224c4 name:ZooKeeperConnection Watcher:127.0.0.1:55219/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1511892 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1511892 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1511907 T4290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54c9b390 name:ZooKeeperConnection Watcher:127.0.0.1:55219 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1511907 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1511938 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1511938 T4292 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32d8aac3 name:ZooKeeperConnection Watcher:127.0.0.1:55219 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1511938 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1511938 T4266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1511953 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1511953 T4266 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1511968 T4266 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1511968 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1511984 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1511984 T4294 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@694b1701 name:ZooKeeperConnection Watcher:127.0.0.1:55219/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1511984 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1511984 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1511999 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1512014 T4288 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1512014 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1512014 T4294 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1512014 T4296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c05f9df name:ZooKeeperConnection Watcher:127.0.0.1:55219/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1512014 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1512014 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1512030 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1512045 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1512060 T4266 oasc.Overseer.start Overseer (id=91039361881145348-127.0.0.1:55219_solr-n_0000000000) starting
[junit4] 2> 1512060 T4266 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1512091 T4266 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1512106 T4266 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1512122 T4298 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1512122 T4297 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1513149 T4296 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1513149 T4297 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1513149 T4297 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> 1513149 T4297 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1513149 T4297 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1513166 T4296 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1513166 T4288 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> 1513166 T4294 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> 1513688 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1513722 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1513739 T4296 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1513739 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1513739 T4297 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1513756 T4296 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1513756 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1513756 T4297 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> 1513756 T4297 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1513772 T4296 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1513890 T4288 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> 1513890 T4294 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> 1515036 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1515070 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1515070 T4300 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46b1f649 name:ZooKeeperConnection Watcher:127.0.0.1:55219/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1515070 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1515086 T4266 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1515086 T4266 oasc.Overseer.start Overseer (id=91039361881145349-127.0.0.1:55219_solr-n_0000000001) starting
[junit4] 2> 1515103 T4302 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1515103 T4301 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1515120 T4301 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1515120 T4301 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> 1515120 T4301 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1515137 T4300 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1515137 T4288 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> 1515137 T4294 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> 1515204 T4300 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1515204 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1515204 T4301 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1515238 T4294 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
[junit4] 2> 1515238 T4266 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91039361881145347-node1_core1-n_0000000000
[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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:126)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:597)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[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:70)
[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:358)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[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 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:70)
[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:358)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1515238 T4301 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:173)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:170)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:654)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:649)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:875)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:226)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:187)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1515255 T4294 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1515255 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1515255 T4300 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1515272 T4288 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1515289 T4266 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55219 55219
[junit4] 2> 1515373 T4301 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1516889 T4294 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:239)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:236)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:236)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:121)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1517714 T4294 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1517714 T4266 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=6FB50D224E2B0925 -Dtests.slow=true -Dtests.locale=ar_JO -Dtests.timezone=Asia/Dushanbe -Dtests.file.encoding=UTF-8
[junit4] ERROR 5.95s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at __randomizedtesting.SeedInfo.seed([6FB50D224E2B0925:6BBD82D15C8EE604]:0)
[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$10.execute(SolrZkClient.java:428)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 1517731 T4266 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1517731 T4266 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1517731 T4303 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1517849 T4266 oasc.ZkTestServer.run start zk server on port:55240
[junit4] 2> 1517849 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1517849 T4309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2324c2d0 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1517849 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1517866 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1517866 T4311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43330df5 name:ZooKeeperConnection Watcher:127.0.0.1:55240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1517866 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1517950 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1517950 T4313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56cc9aad name:ZooKeeperConnection Watcher:127.0.0.1:55240 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1517950 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1517950 T4266 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1517950 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1517967 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1517967 T4314 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1517967 T4318 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e7a3493 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1517967 T4314 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1517967 T4317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20eaaae7 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1517967 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1517967 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1517967 T4266 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1517984 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1517984 T4266 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1517984 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1518001 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1518001 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1518001 T4314 oasc.Overseer.start Overseer (id=91039362270953475-127.0.0.1:55240_solr-n_0000000000) starting
[junit4] 2> 1518018 T4317 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1518018 T4266 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1518018 T4314 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1518034 T4314 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1518034 T4314 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1518051 T4314 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1518051 T4320 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1518051 T4319 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1518051 T4314 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1518051 T4322 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@211b80dd name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1518051 T4314 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1518068 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1518068 T4314 oasc.Overseer.start Overseer (id=91039362270953477-127.0.0.1:55240_solr-n_0000000001) starting
[junit4] 2> 1518085 T4324 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1518085 T4323 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1518102 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1518102 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1518102 T4323 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1518102 T4323 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1518102 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518119 T4317 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> 1518573 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1518590 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1518607 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518624 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518624 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1518624 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1518641 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1518641 T4323 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1518641 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1518658 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518658 T4326 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b7d6c40 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1518658 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1518658 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1518658 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1518675 T4326 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1518675 T4317 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1518675 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518675 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1518691 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1518691 T4323 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1518708 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518708 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1518826 T4326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1518826 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1518944 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1518944 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518944 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518944 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1518961 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1518961 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1518961 T4323 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1518961 T4323 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1518978 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519096 T4326 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519096 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519483 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1519500 T4326 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1519500 T4317 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1519500 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519517 T4326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1519534 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519534 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519534 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519534 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519551 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519668 T4320 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:156)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1519668 T4320 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91039362270953475-127.0.0.1:55240_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1519668 T4320 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:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:163)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1519668 T4320 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91039362270953475-127.0.0.1:55240_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1519668 T4326 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> 1519736 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519736 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1519736 T4328 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79f8087a name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1519736 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1519736 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1519753 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1519753 T4328 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1519770 T4326 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1519770 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519770 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519770 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519770 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1519770 T4323 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519786 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1519786 T4323 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1519786 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519803 T4328 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1519803 T4326 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1519803 T4304 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1436fd150bd0006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1519820 T4328 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1519820 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519820 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1519820 T4323 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1519820 T4323 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1519837 T4322 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519854 T4314 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1519854 T4314 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1519854 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1519854 T4330 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38bbee1 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1519854 T4314 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1519871 T4332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15e633e name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1519871 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1519871 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1519871 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1519887 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1519887 T4314 oasc.Overseer.start Overseer (id=91039362270953480-127.0.0.1:55240_solr-n_0000000002) starting
[junit4] 2> 1519887 T4332 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1519887 T4328 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1519904 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1519904 T4334 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1519921 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519921 T4333 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1519921 T4333 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1519921 T4333 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1519921 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519921 T4332 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519921 T4328 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519938 T4333 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1519938 T4333 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1519938 T4328 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519938 T4332 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519955 T4323 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1519955 T4333 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1519955 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1519972 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1519972 T4328 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519972 T4332 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1519988 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520005 T4333 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520005 T4333 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520005 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520123 T4328 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520123 T4332 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520140 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520140 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520140 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520140 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520140 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1520157 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520157 T4333 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1520157 T4333 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520174 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520174 T4332 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520174 T4328 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520191 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520191 T4332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1520207 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520224 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520342 T4332 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> 1520410 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520410 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1520410 T4336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b407510 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1520410 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1520410 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1520426 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1520443 T4332 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1520443 T4336 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1520460 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520460 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520460 T4330 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520460 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1520477 T4333 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520477 T4333 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520477 T4333 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520494 T4314 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1520494 T4333 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-0000000012
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:173)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:170)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:170)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.remove(DistributedQueue.java:170)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:445)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:190)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 1520494 T4314 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1520494 T4332 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520511 T4336 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520511 T4338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ae84c05 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1520511 T4314 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1520511 T4336 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1520511 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1520528 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1520544 T4314 oasc.Overseer.start Overseer (id=91039362270953483-127.0.0.1:55240_solr-n_0000000003) starting
[junit4] 2> 1520561 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1520561 T4340 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@570d891 name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1520561 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1520578 T4342 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1520578 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1520578 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1520595 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520595 T4341 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1520595 T4340 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1520595 T4336 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1520595 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520595 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520595 T4336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520595 T4340 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520612 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1520612 T4341 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1520629 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520629 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520629 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520629 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520645 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520645 T4336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520645 T4340 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520662 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520662 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520662 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520679 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520679 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520696 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1520696 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520696 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520814 T4336 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520814 T4340 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1520864 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520864 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520864 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520864 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520864 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1520881 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520881 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 1520881 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1520898 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520898 T4340 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520898 T4336 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1520915 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1520915 T4340 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1520932 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1520949 T4338 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1521067 T4340 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> 1521117 T4317 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1521117 T4317 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[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.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1521134 T4266 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1521134 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1521134 T4344 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4306223d name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1521134 T4266 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1521134 T4266 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1521151 T4266 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1521168 T4314 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1521168 T4344 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1521168 T4340 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1521168 T4314 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1521168 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1521168 T4346 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2474c1ef name:ZooKeeperConnection Watcher:127.0.0.1:55240/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1521168 T4314 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1521201 T4314 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1521201 T4344 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1521201 T4314 oasc.Overseer.start Overseer (id=91039362270953486-127.0.0.1:55240_solr-n_0000000004) starting
[junit4] 2> 1521218 T4344 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1521218 T4266 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1521235 T4348 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1521235 T4347 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1521252 T4266 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1521252 T4347 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1521252 T4347 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[...truncated too long message...]
a:100)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:94)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:61)
[junit4] 2> ... 8 more
[junit4] 2>
[junit4] 2> 1560694 T4547 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[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.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1561355 T4547 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1560639 T4541 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[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.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1561355 T4541 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1561355 T4549 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1561355 T4266 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignmentBigger
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1561355 T4266 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1561355 T4266 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1563949 T4266 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=ar_JO, timezone=Asia/Dushanbe
[junit4] 2> NOTE: Windows 7 6.1 amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=2,threads=1,free=94167056,total=169840640
[junit4] 2> NOTE: All tests run in this JVM: [PathHierarchyTokenizerFactoryTest, DisMaxRequestHandlerTest, CircularListTest, TestConfig, LoggingHandlerTest, TestSolr4Spatial, TestLMDirichletSimilarityFactory, TestRangeQuery, CachingDirectoryFactoryTest, SolrCoreTest, TestNRTOpen, TestSystemIdResolver, TestSolrQueryParser, TestBinaryResponseWriter, TestCSVLoader, SolrIndexSplitterTest, TestDynamicFieldResource, TestCoreContainer, TestCollationField, BasicDistributedZk2Test, TestPHPSerializedResponseWriter, TestReload, ResponseLogComponentTest, SpatialFilterTest, StatelessScriptUpdateProcessorFactoryTest, TestBadConfig, TestArbitraryIndexDir, BasicDistributedZkTest, TestIndexSearcher, DeleteReplicaTest, TestSurroundQueryParser, TestWriterPerf, CacheHeaderTest, TestUpdate, TestPerFieldSimilarity, SignatureUpdateProcessorFactoryTest, TestSolrQueryParserDefaultOperatorResource, DirectUpdateHandlerOptimizeTest, AutoCommitTest, TestSolrIndexConfig, CoreAdminHandlerTest, ShardRoutingCustomTest, SliceStateUpdateTest, TestDistributedSearch, CoreAdminCreateDiscoverTest, UnloadDistributedZkTest, FileBasedSpellCheckerTest, SliceStateTest, HighlighterTest, TestOmitPositions, SolrRequestParserTest, TestSolrJ, TestRandomDVFaceting, TestCollationKeyRangeQueries, ClusterStateUpdateTest, TestFastOutputStream, TestDistributedMissingSort, TestRandomFaceting, TestSolrDeletionPolicy2, TestDefaultSimilarityFactory, FieldAnalysisRequestHandlerTest, AnalysisAfterCoreReloadTest, StressHdfsTest, TestSearchPerf, DistributedSpellCheckComponentTest, TestRealTimeGet, DistanceFunctionTest, TestSolrCoreProperties, ParsingFieldUpdateProcessorsTest, TestJmxMonitoredMap, DebugComponentTest, TestFastLRUCache, TestDFRSimilarityFactory, RecoveryZkTest, SOLR749Test, TestFaceting, TestValueSourceCache, TestCollationFieldDocValues, TestDocumentBuilder, UniqFieldsUpdateProcessorFactoryTest, SpellCheckComponentTest, NoCacheHeaderTest, QueryParsingTest, HighlighterConfigTest, EchoParamsTest, TestDefaultSearchFieldResource, HdfsRecoveryZkTest, SynonymTokenizerTest, TestCloudManagedSchemaAddField, TestFoldingMultitermQuery, TestFieldResource, SuggesterWFSTTest, DocValuesMultiTest, QueryElevationComponentTest, DistributedQueryComponentCustomSortTest, SimpleFacetsTest, TestQuerySenderNoQuery, TestRandomMergePolicy, MBeansHandlerTest, IndexBasedSpellCheckerTest, OpenExchangeRatesOrgProviderTest, StatsComponentTest, ConvertedLegacyTest, TestSolrXmlPersistence, TestFieldTypeResource, SpellingQueryConverterTest, TestUtils, TestBM25SimilarityFactory, TestSweetSpotSimilarityFactory, HardAutoCommitTest, TestDistributedGrouping, CurrencyFieldXmlFileTest, HdfsCollectionsAPIDistributedZkTest, NumericFieldsTest, IndexSchemaTest, SoftAutoCommitTest, InfoHandlerTest, TestShardHandlerFactory, ZkCLITest, QueryEqualityTest, URLClassifyProcessorTest, MoreLikeThisHandlerTest, FieldMutatingUpdateProcessorTest, HdfsDirectoryTest, SuggesterFSTTest, TestStressUserVersions, LeaderElectionTest, BadIndexSchemaTest, SchemaVersionSpecificBehaviorTest, XsltUpdateRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, TermVectorComponentTest, TestSolrXMLSerializer, BlockCacheTest, TestStressLucene, TestReloadAndDeleteDocs, TestCloudManagedSchema, ShowFileRequestHandlerTest, TestQueryTypes, TestJmxIntegration, RequestHandlersTest, SolrCmdDistributorTest, TestFieldCollectionResource, ShardRoutingTest, TestSerializedLuceneMatchVersion, TestExtendedDismaxParser, ZkControllerTest, BadComponentTest, SolrPluginUtilsTest, TestNoOpRegenerator, HdfsChaosMonkeySafeLeaderTest, JSONWriterTest, MinimalSchemaTest, OverseerTest]
[junit4] Completed in 54.85s, 8 tests, 1 error <<< FAILURES!
[...truncated 596 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:459: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:439: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:491: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1307: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 error, 42 ignored (13 assumptions)
Total time: 81 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure