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/07/11 19:33:29 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_60) - Build #
4087 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/4087/
Java: 32bit/jdk1.7.0_60 -server -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([F3843FDF4B4C5CEE:F78CB02C59E9B3CF]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:143)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.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:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:130)
... 48 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:135)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 49 more
Build Log:
[...truncated 11630 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-F3843FDF4B4C5CEE-001\init-core-data-001
[junit4] 2> 2645916 T8195 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 2645916 T8195 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2645916 T8195 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2645921 T8195 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 2645924 T8195 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2645927 T8196 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2646056 T8195 oasc.ZkTestServer.run start zk server on port:59363
[junit4] 2> 2646060 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2646070 T8202 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d38f23 name:ZooKeeperConnection Watcher:127.0.0.1:59363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2646071 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2646076 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2646080 T8204 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4062ae name:ZooKeeperConnection Watcher:127.0.0.1:59363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2646080 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2646088 T8197 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1472655d9040001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2646090 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2646095 T8206 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a70596 name:ZooKeeperConnection Watcher:127.0.0.1:59363 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2646095 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2646095 T8195 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2646108 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2646119 T8195 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2646127 T8195 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2646132 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2646145 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2646150 T8208 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17af73c name:ZooKeeperConnection Watcher:127.0.0.1:59363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2646150 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2646156 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2646166 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2646176 T8208 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2646176 T8202 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2646179 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2646184 T8210 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9319 name:ZooKeeperConnection Watcher:127.0.0.1:59363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2646184 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2646189 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2646194 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2646212 T8195 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59363_solr
[junit4] 2> 2646213 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2646222 T8195 oasc.Overseer.start Overseer (id=92084467539378180-127.0.0.1:59363_solr-n_0000000000) starting
[junit4] 2> 2646229 T8195 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2646241 T8195 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2646251 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2646262 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2646273 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2646286 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2646305 T8212 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2646311 T8211 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2646318 T8211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2646321 T8211 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> 2646321 T8211 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2646322 T8211 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2646330 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2646331 T8208 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> 2646332 T8202 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> 2646961 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2646994 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2647011 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647013 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2647016 T8211 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2647019 T8202 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2647020 T8208 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2647032 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647032 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2647037 T8214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b46d8f name:ZooKeeperConnection Watcher:127.0.0.1:59363/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2647037 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2647041 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2647046 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2647049 T8214 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2647049 T8202 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2647053 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647053 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2647054 T8211 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> 2647056 T8211 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2647058 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647063 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2647070 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647075 T8210 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2647208 T8214 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> 2647209 T8202 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> 2647210 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2647215 T8211 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-work/qn-0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.remove(DistributedQueue.java:213)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:625)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:264)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2647217 T8211 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59363_solr
[junit4] 2> 2647220 T8215 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> 2647220 T8202 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2647220 T8214 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2647227 T8197 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1472655d9040000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2647228 T8195 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59363 59363
[junit4] 2> 2648912 T8212 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2650154 T8196 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59363 59363
[junit4] 2> 2650157 T8195 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 2650167 T8195 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 2650172 T8195 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2650175 T8216 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2650304 T8195 oasc.ZkTestServer.run start zk server on port:59384
[junit4] 2> 2650308 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2650318 T8222 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77f903 name:ZooKeeperConnection Watcher:127.0.0.1:59384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2650319 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2650334 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2650338 T8224 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@481c43 name:ZooKeeperConnection Watcher:127.0.0.1:59384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2650338 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2650338 T8195 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2650355 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2650358 T8226 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11f133b name:ZooKeeperConnection Watcher:127.0.0.1:59384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2650361 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2650361 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2650368 T8195 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2650377 T8195 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2650384 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2650396 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2650399 T8228 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a06426 name:ZooKeeperConnection Watcher:127.0.0.1:59384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2650400 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2650405 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2650415 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2650424 T8226 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2650425 T8228 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2650429 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2650433 T8230 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13c5b10 name:ZooKeeperConnection Watcher:127.0.0.1:59384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2650433 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2650439 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2650450 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2650465 T8195 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59384_solr
[junit4] 2> 2650465 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2650475 T8195 oasc.Overseer.start Overseer (id=92084467817840644-127.0.0.1:59384_solr-n_0000000000) starting
[junit4] 2> 2650481 T8195 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2650493 T8195 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2650504 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2650514 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2650524 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2650537 T8195 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2650556 T8232 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2650560 T8231 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2651860 T8230 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2651868 T8231 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2651870 T8231 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> 2651870 T8231 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2651870 T8231 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2651879 T8230 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2651883 T8226 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> 2651883 T8228 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> 2652509 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2652548 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2652568 T8230 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2652574 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2652580 T8231 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2652589 T8230 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2652589 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2652599 T8231 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> 2652599 T8231 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2652626 T8230 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2652760 T8228 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> 2652760 T8226 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> 2653160 T8232 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2653975 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2653999 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2654002 T8234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16de6dd name:ZooKeeperConnection Watcher:127.0.0.1:59384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2654002 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2654007 T8231 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59384_solr
[junit4] 2> 2654010 T8235 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> 2654018 T8195 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59384_solr
[junit4] 2> 2654020 T8195 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2654026 T8195 oasc.Overseer.start Overseer (id=92084467817840645-127.0.0.1:59384_solr-n_0000000001) starting
[junit4] 2> 2654063 T8237 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2654067 T8236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2654070 T8236 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2654072 T8236 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> 2654073 T8236 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2654075 T8226 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> 2654075 T8228 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> 2654081 T8236 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2654085 T8236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2654086 T8236 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> 2654086 T8236 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2654089 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654210 T8228 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> 2654210 T8226 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> 2654259 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654260 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654261 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654260 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2654266 T8236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2654274 T8228 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
[junit4] 2> 2654275 T8195 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92084467817840643-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:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:606)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.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:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2654277 T8236 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:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[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:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1100)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:358)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:240)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2654277 T8228 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2654278 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2654281 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654285 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654288 T8236 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2654291 T8234 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2654413 T8226 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> 2654413 T8228 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> 2655452 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2656629 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2657807 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2658987 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2660164 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2661341 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2662518 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2663695 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2664869 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2665929 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2666989 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2668048 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2669108 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2670170 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2671229 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2671241 T8226 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2671242 T8228 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2671250 T8217 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1472655e99d0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2671251 T8195 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59384 59384
[junit4] 2> 2671999 T8237 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2673623 T8216 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59384 59384
[junit4] 2> 2673625 T8195 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 2673626 T8236 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59384_solr
[junit4] 2> 2673629 T8238 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=F3843FDF4B4C5CEE -Dtests.slow=true -Dtests.locale=bg -Dtests.timezone=UCT -Dtests.file.encoding=US-ASCII
[junit4] ERROR 23.5s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([F3843FDF4B4C5CEE:F78CB02C59E9B3CF]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:143)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:660)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:130)
[junit4] > ... 48 more
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:135)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 49 more
[junit4] 2> 2673655 T8195 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2673656 T8195 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2673657 T8239 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2673763 T8195 oasc.ZkTestServer.run start zk server on port:59405
[junit4] 2> 2673766 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673773 T8245 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@176fc66 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673774 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673776 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673780 T8247 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19154db name:ZooKeeperConnection Watcher:127.0.0.1:59405 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673781 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673791 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673794 T8249 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b503a4 name:ZooKeeperConnection Watcher:127.0.0.1:59405 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673794 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673795 T8195 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2673805 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2673816 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673819 T8250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673822 T8252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5915f3 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673822 T8254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b02272 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673822 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673823 T8250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673827 T8195 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2673828 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2673835 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2673837 T8195 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2673840 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2673843 T8250 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59405_solr
[junit4] 2> 2673843 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2673845 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2673847 T8250 oasc.Overseer.start Overseer (id=92084469356560388-127.0.0.1:59405_solr-n_0000000000) starting
[junit4] 2> 2673849 T8252 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2673850 T8250 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2673851 T8195 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2673855 T8250 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2673860 T8250 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2673865 T8250 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2673869 T8250 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2673874 T8250 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2673881 T8250 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2673882 T8256 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2673885 T8250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2673886 T8258 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ba613a name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2673887 T8250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2673888 T8256 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92084469356560388-127.0.0.1:59405_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2673888 T8256 oasc.SolrException.log ERROR :org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/collection-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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[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:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:99)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.getTailId(DistributedQueue.java:483)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:245)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2673889 T8256 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[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:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[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:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:416)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:260)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2673894 T8250 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59405_solr
[junit4] 2> 2673894 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2673897 T8250 oasc.Overseer.start Overseer (id=92084469356560389-127.0.0.1:59405_solr-n_0000000001) starting
[junit4] 2> 2673916 T8260 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2673918 T8259 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2673923 T8259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2673923 T8259 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> 2673924 T8259 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2673924 T8259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2673928 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2673929 T8252 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> 2674381 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2674406 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2674423 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674430 T8259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2674431 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674432 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2674442 T8259 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> 2674442 T8259 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2674448 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674449 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2674451 T8262 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c95d9 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2674451 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2674453 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2674457 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2674460 T8252 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2674460 T8262 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2674462 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674462 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2674464 T8259 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> 2674464 T8259 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2674468 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674471 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2674578 T8252 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> 2674579 T8262 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> 2674684 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2674692 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674692 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674693 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674697 T8259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2674699 T8259 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> 2674699 T8259 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2674699 T8259 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2674706 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2674816 T8252 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> 2674817 T8262 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> 2675217 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675237 T8262 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2675241 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675243 T8262 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2675257 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675257 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675258 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675264 T8259 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675272 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675378 T8262 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> 2675445 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675450 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2675452 T8264 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f3a40 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2675453 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2675456 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2675464 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2675471 T8264 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675473 T8262 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675501 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675501 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675501 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675501 T8258 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675502 T8250 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2675506 T8250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2675508 T8266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63d9ba name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2675508 T8250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2675510 T8259 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59405_solr
[junit4] 2> 2675511 T8267 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> 2675516 T8250 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59405_solr
[junit4] 2> 2675516 T8264 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2675516 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2675519 T8264 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2675520 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675521 T8250 oasc.Overseer.start Overseer (id=92084469356560392-127.0.0.1:59405_solr-n_0000000002) starting
[junit4] 2> 2675530 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2675532 T8270 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a81b45 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2675533 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2675537 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2675538 T8271 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2675541 T8268 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2675541 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2675545 T8268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675545 T8264 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675546 T8270 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675546 T8268 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> 2675547 T8268 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2675548 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675548 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675550 T8270 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> 2675550 T8264 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> 2675557 T8268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675557 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675558 T8268 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> 2675558 T8268 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2675561 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675564 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675565 T8268 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> 2675565 T8268 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2675568 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675667 T8264 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> 2675667 T8270 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> 2675748 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675756 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675757 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675757 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675757 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675763 T8268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675764 T8268 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> 2675764 T8268 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2675768 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675769 T8270 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2675770 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675771 T8270 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2675780 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675785 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675884 T8270 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> 2675962 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2675967 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2675970 T8273 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14fbbac name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2675971 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2675975 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2675981 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2675987 T8270 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675988 T8273 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2675993 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675994 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675994 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2675994 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2675999 T8268 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2676000 T8268 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> 2676001 T8268 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2676006 T8266 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2676013 T8250 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2676017 T8273 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2676018 T8270 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2676022 T8250 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2676028 T8273 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2676029 T8275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19aaa8 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2676029 T8250 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2676030 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2676032 T8268 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59405_solr
[junit4] 2> 2676036 T8276 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> 2676047 T8250 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59405_solr
[junit4] 2> 2676047 T8250 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2676060 T8250 oasc.Overseer.start Overseer (id=92084469356560395-127.0.0.1:59405_solr-n_0000000003) starting
[junit4] 2> 2676062 T8195 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2676065 T8278 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d082e7 name:ZooKeeperConnection Watcher:127.0.0.1:59405/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2676065 T8195 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2676067 T8195 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2676070 T8195 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2676072 T8273 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2676073 T8278 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2676074 T8195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2676077 T8280 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2676079 T8279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2676080 T8279 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2676081 T8279 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> 2676081 T8195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2676082 T8279 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2676083 T8273 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> 2676084 T8278 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> 2676085 T8279 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2676088 T8279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2676089 T8279 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> 2676089 T8279 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[...truncated too long message...]
odes size: 1)
[junit4] 2> 2701452 T8547 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> 2701480 T8553 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2701481 T8538 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1472656a6bc0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2701484 T8538 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1472656a6bc0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2701484 T8195 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59699 59699
[junit4] 2> 2701775 T8551 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2703041 T8537 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59699 59699
[junit4] 2> 2703043 T8195 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 2703044 T8550 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59699_solr
[junit4] 2> 2703046 T8554 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[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:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:316)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:288)
[junit4] 2>
[junit4] 2> 2705115 T8195 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-F3843FDF4B4C5CEE-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=bg, timezone=UCT
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60 (32-bit)/cpus=2,threads=1,free=96599112,total=477605888
[junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, ExternalFileFieldSortTest, TestArbitraryIndexDir, TestValueSourceCache, MBeansHandlerTest, TermVectorComponentDistributedTest, TestWordDelimiterFilterFactory, TestSimpleQParserPlugin, PingRequestHandlerTest, TestFuzzyAnalyzedSuggestions, TestDistributedGrouping, TestTolerantSearch, BlockDirectoryTest, InfoHandlerTest, SortByFunctionTest, TestSchemaResource, TestUniqueKeyFieldResource, TestIndexingPerformance, TestCoreContainer, FullSolrCloudDistribCmdsTest, OpenCloseCoreStressTest, OverseerStatusTest, BasicZkTest, URLClassifyProcessorTest, DistribDocExpirationUpdateProcessorTest, HdfsWriteToMultipleCollectionsTest, AnalysisAfterCoreReloadTest, BasicDistributedZkTest, CoreMergeIndexesAdminHandlerTest, DocValuesTest, AnalysisErrorHandlingTest, UUIDFieldTest, TestClassNameShortening, RankQueryTest, StatelessScriptUpdateProcessorFactoryTest, HighlighterConfigTest, SolrCmdDistributorTest, FileBasedSpellCheckerTest, NotRequiredUniqueKeyTest, TestBinaryResponseWriter, PathHierarchyTokenizerFactoryTest, DirectSolrSpellCheckerTest, TestExtendedDismaxParser, TestDynamicFieldCollectionResource, RegexBoostProcessorTest, TestJoin, TestDistribDocBasedVersion, TestMissingGroups, TestFieldTypeCollectionResource, FileUtilsTest, CursorMarkTest, SpellPossibilityIteratorTest, TestCopyFieldCollectionResource, CoreAdminCreateDiscoverTest, DistributedQueryComponentCustomSortTest, TestBadConfig, AsyncMigrateRouteKeyTest, TestBinaryField, PreAnalyzedFieldTest, DirectUpdateHandlerTest, TimeZoneUtilsTest, RequiredFieldsTest, TestHighlightDedupGrouping, HdfsChaosMonkeySafeLeaderTest, SoftAutoCommitTest, TestPhraseSuggestions, TestWriterPerf, TestInfoStreamLogging, TestLMJelinekMercerSimilarityFactory, TestManagedSchemaFieldResource, TestZkChroot, TestReplicationHandler, FastVectorHighlighterTest, TestQuerySenderListener, TestBlendedInfixSuggestions, SuggesterTSTTest, CachingDirectoryFactoryTest, TestManagedSchema, BadIndexSchemaTest, TestManagedResourceStorage, SimpleFacetsTest, HardAutoCommitTest, LegacyHTMLStripCharFilterTest, HdfsCollectionsAPIDistributedZkTest, DocumentBuilderTest, OverseerCollectionProcessorTest, TestRandomMergePolicy, TestPartialUpdateDeduplication, ChangedSchemaMergeTest, DistribCursorPagingTest, TestFaceting, CopyFieldTest, TestChildDocTransformer, CSVRequestHandlerTest, TestRandomDVFaceting, ParsingFieldUpdateProcessorsTest, SearchHandlerTest, DistanceFunctionTest, TestNonNRTOpen, CoreAdminRequestStatusTest, MoreLikeThisHandlerTest, PrimitiveFieldTypeTest, FieldMutatingUpdateProcessorTest, TestSolrDeletionPolicy2, TestCustomSort, AssignTest, AddBlockUpdateTest, LukeRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, TestNonDefinedSimilarityFactory, TestFoldingMultitermQuery, DistributedQueryElevationComponentTest, TestNoOpRegenerator, TestExceedMaxTermLength, ReturnFieldsTest, CollectionsAPIDistributedZkTest, StatsComponentTest, TestFileDictionaryLookup, ConvertedLegacyTest, ClusterStateUpdateTest, SuggesterWFSTTest, TestOverriddenPrefixQueryForCustomFieldType, TestRangeQuery, HighlighterTest, TestLMDirichletSimilarityFactory, TestSolrXMLSerializer, TestSolrDeletionPolicy1, TestSolrQueryParserResource, UniqFieldsUpdateProcessorFactoryTest, AutoCommitTest, SuggesterFSTTest, TestLazyCores, TestSchemaSimilarityResource, TestCSVLoader, TestStressRecovery, SSLMigrationTest, ZkSolrClientTest, AtomicUpdatesTest, BasicFunctionalityTest, TestCSVResponseWriter, ZkControllerTest, DefaultValueUpdateProcessorTest, SOLR749Test, SimplePostToolTest, TestAtomicUpdateErrorCases, ShardSplitTest, PolyFieldTest, BadCopyFieldTest, TestUpdate, TestRequestStatusCollectionAPI, SpatialFilterTest, TestCodecSupport, CollectionsAPIAsyncDistributedZkTest, BinaryUpdateRequestHandlerTest, TestSystemIdResolver, TestJmxMonitoredMap, TestComponentsName, TestSearchPerf, HdfsSyncSliceTest, DeleteReplicaTest, TestPHPSerializedResponseWriter, ShowFileRequestHandlerTest, JsonLoaderTest, OverseerRolesTest, TestSolrIndexConfig, SolrRequestParserTest, TestStressUserVersions, SolrCoreCheckLockOnStartupTest, TestPostingsSolrHighlighter, DistributedTermsComponentTest, TestLuceneMatchVersion, TestHighFrequencyDictionaryFactory, DirectSolrConnectionTest, AnalyticsMergeStrategyTest, SpellingQueryConverterTest, TestSolrXmlPersistor, HdfsDirectoryTest, TestSuggestSpellingConverter, MultiThreadedOCPTest, TestManagedResource, BasicDistributedZk2Test, PrimUtilsTest, TestCollationField, TestReplicationHandlerBackup, SyncSliceTest, AnalyticsQueryTest, TestSerializedLuceneMatchVersion, HdfsLockFactoryTest, TestRealTimeGet, AddSchemaFieldsUpdateProcessorFactoryTest, TestAddFieldRealTimeGet, TestMultiCoreConfBootstrap, ResponseHeaderTest, TestDocumentBuilder, PluginInfoTest, TestCollationKeyRangeQueries, DistributedSuggestComponentTest, TestShardHandlerFactory, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OverseerTest]
[junit4] Completed in 59.24s, 9 tests, 1 error <<< FAILURES!
[...truncated 623 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: 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:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1299: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:923: There were test failures: 407 suites, 1660 tests, 1 error, 42 ignored (21 assumptions)
Total time: 120 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.7.0_60 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any