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/05/14 20:02:53 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_60-ea-b15) -
Build # 4034 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4034/
Java: 32bit/jdk1.7.0_60-ea-b15 -server -XX:+UseG1GC
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([E3848C1BF089F548:E78C03E8E22C1A69]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
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:360)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$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:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 47 more
Build Log:
[...truncated 11226 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-E3848C1BF089F548-001\init-core-data-001
[junit4] 2> 2395718 T8326 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 2395718 T8326 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2395719 T8326 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2395723 T8326 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 2395725 T8326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2395726 T8327 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2395834 T8326 oasc.ZkTestServer.run start zk server on port:61848
[junit4] 2> 2395838 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2395844 T8333 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a2b17 name:ZooKeeperConnection Watcher:127.0.0.1:61848/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2395844 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2395847 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2395850 T8335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15466e6 name:ZooKeeperConnection Watcher:127.0.0.1:61848 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2395850 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2395854 T8328 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd17920001, 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> 2395857 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2395860 T8337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@124e7c4 name:ZooKeeperConnection Watcher:127.0.0.1:61848 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2395861 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2395861 T8326 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2395867 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2395868 T8328 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd17920002, 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> 2395873 T8326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2395877 T8326 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2395881 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2395888 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2395890 T8339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17d25ea name:ZooKeeperConnection Watcher:127.0.0.1:61848/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2395891 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2395892 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2395897 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2395904 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2395906 T8341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1acd116 name:ZooKeeperConnection Watcher:127.0.0.1:61848/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2395907 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2395908 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2395912 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2395919 T8326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61848_solr
[junit4] 2> 2395920 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2395924 T8326 oasc.Overseer.start Overseer (id=91756225713274884-127.0.0.1:61848_solr-n_0000000000) starting
[junit4] 2> 2395927 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2395933 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2395940 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2395950 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2395958 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2395964 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2395974 T8343 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2395976 T8343 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:61848_solr
[junit4] 2> 2395976 T8342 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2395981 T8342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2395982 T8342 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> 2395982 T8342 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2395982 T8342 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2395986 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2395988 T8339 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> 2395988 T8333 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> 2396519 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2396537 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2396546 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396547 T8326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2396549 T8342 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2396556 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2396556 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396559 T8345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fa74bb name:ZooKeeperConnection Watcher:127.0.0.1:61848/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2396559 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2396561 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2396564 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2396574 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396575 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2396576 T8342 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> 2396576 T8342 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2396580 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396584 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2396592 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396600 T8341 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2396709 T8345 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> 2396710 T8333 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> 2396712 T8326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2396717 T8328 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd17920004, 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> 2396721 T8328 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd17920005, 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> 2396724 T8328 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd17920000, 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> 2396724 T8326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61848 61848
[junit4] 2> 2398333 T8342 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:178)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:265)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2399154 T8342 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:61848_solr
[junit4] 2> 2399156 T8327 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61848 61848
[junit4] 2> 2399157 T8346 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 2399158 T8326 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 2399167 T8326 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 2399170 T8326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2399171 T8347 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2399278 T8326 oasc.ZkTestServer.run start zk server on port:61869
[junit4] 2> 2399283 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2399288 T8353 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b782b name:ZooKeeperConnection Watcher:127.0.0.1:61869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2399289 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2399292 T8348 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd25060000, 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> 2399294 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2399297 T8355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@167b515 name:ZooKeeperConnection Watcher:127.0.0.1:61869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2399297 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2399297 T8326 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2399306 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2399308 T8357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fe27f name:ZooKeeperConnection Watcher:127.0.0.1:61869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2399309 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2399309 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2399314 T8326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2399319 T8326 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2399322 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2399329 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2399332 T8359 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e728b name:ZooKeeperConnection Watcher:127.0.0.1:61869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2399332 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2399334 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2399339 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2399347 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2399350 T8361 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e32330 name:ZooKeeperConnection Watcher:127.0.0.1:61869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2399351 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2399352 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2399356 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2399365 T8326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61869_solr
[junit4] 2> 2399365 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2399369 T8326 oasc.Overseer.start Overseer (id=91756225938980868-127.0.0.1:61869_solr-n_0000000000) starting
[junit4] 2> 2399373 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2399379 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2399387 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2399394 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2399401 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2399409 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2399422 T8363 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2399425 T8363 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:61869_solr
[junit4] 2> 2399425 T8362 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2400509 T8361 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2400513 T8362 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2400515 T8362 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> 2400515 T8362 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2400515 T8362 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2400521 T8361 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2400523 T8357 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> 2400523 T8359 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> 2401102 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2401122 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2401132 T8361 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2401134 T8326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2401137 T8362 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2401139 T8361 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2401139 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2401145 T8362 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> 2401145 T8362 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2401151 T8361 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2401275 T8357 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> 2401275 T8359 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> 2402529 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2402542 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2402544 T8365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7c8cc name:ZooKeeperConnection Watcher:127.0.0.1:61869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2402545 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2402546 T8362 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:61869_solr
[junit4] 2> 2402550 T8366 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 2402556 T8326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61869_solr
[junit4] 2> 2402556 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2402561 T8326 oasc.Overseer.start Overseer (id=91756225938980869-127.0.0.1:61869_solr-n_0000000001) starting
[junit4] 2> 2402585 T8368 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2402586 T8367 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2402586 T8368 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:61869_solr
[junit4] 2> 2402588 T8367 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2402590 T8367 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> 2402590 T8367 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2402595 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402596 T8359 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> 2402596 T8357 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> 2402662 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402663 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2402666 T8367 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2402674 T8359 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91756225938980867-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:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2402677 T8326 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91756225938980867-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$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:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[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:360)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
[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:360)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2402680 T8359 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2402681 T8367 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:1066)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:346)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2402683 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2402685 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402691 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402693 T8367 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2402695 T8359 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2402697 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402705 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402706 T8367 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2402711 T8365 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2402834 T8359 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> 2402835 T8357 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> 2403876 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2405068 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2406260 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2407454 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2408646 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2409838 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2411031 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2412222 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2413305 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2414378 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2415450 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2416524 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2417597 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2418672 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2419746 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2419761 T8326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61869 61869
[junit4] 2> 2422168 T8347 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61869 61869
[junit4] 2> 2422169 T8326 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 2422170 T8367 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:61869_solr
[junit4] 2> 2422173 T8369 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:306)
[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:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=E3848C1BF089F548 -Dtests.slow=true -Dtests.locale=en_IE -Dtests.timezone=America/Chihuahua -Dtests.file.encoding=UTF-8
[junit4] ERROR 23.0s | 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([E3848C1BF089F548:E78C03E8E22C1A69]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$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:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > ... 47 more
[junit4] 2> 2422205 T8326 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 2422207 T8326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2422209 T8370 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2422315 T8326 oasc.ZkTestServer.run start zk server on port:61890
[junit4] 2> 2422317 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2422328 T8376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c77e84 name:ZooKeeperConnection Watcher:127.0.0.1:61890/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2422329 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2422333 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2422337 T8378 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1136d0d name:ZooKeeperConnection Watcher:127.0.0.1:61890 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2422338 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2422341 T8371 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd7f040001, 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> 2422343 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2422347 T8380 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1109e31 name:ZooKeeperConnection Watcher:127.0.0.1:61890 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2422347 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2422348 T8326 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2422359 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2422360 T8371 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd7f040002, 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> 2422364 T8326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2422368 T8326 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2422371 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2422377 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2422379 T8382 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1950014 name:ZooKeeperConnection Watcher:127.0.0.1:61890/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2422379 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2422380 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2422384 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2422391 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2422393 T8384 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@179f96e name:ZooKeeperConnection Watcher:127.0.0.1:61890/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2422393 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2422394 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2422398 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2422407 T8326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61890_solr
[junit4] 2> 2422408 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2422412 T8326 oasc.Overseer.start Overseer (id=91756227448799236-127.0.0.1:61890_solr-n_0000000000) starting
[junit4] 2> 2422416 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2422421 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2422428 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2422434 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2422442 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2422450 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2422464 T8386 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2422466 T8386 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:61890_solr
[junit4] 2> 2422469 T8385 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2422475 T8385 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2422476 T8385 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2422476 T8385 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 2422477 T8385 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard12
[junit4] 2> 2422482 T8384 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2422484 T8376 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> 2422485 T8382 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> 2423002 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard12/election
[junit4] 2> 2423019 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard12
[junit4] 2> 2423027 T8384 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2423028 T8326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2423030 T8371 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd7f040004, 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> 2423034 T8371 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd7f040003, 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> 2423038 T8326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61890 61890
[junit4] 2> 2424471 T8385 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /live_nodes
[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.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:437)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:242)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:234)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2425202 T8385 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:61890_solr
[junit4] 2> 2425203 T8370 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61890 61890
[junit4] 2> 2425204 T8387 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 2425206 T8326 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 2425214 T8326 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 2425217 T8326 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2425218 T8388 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2425314 T8326 oasc.ZkTestServer.run start zk server on port:61908
[junit4] 2> 2425316 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2425322 T8394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19166b3 name:ZooKeeperConnection Watcher:127.0.0.1:61908 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2425323 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2425325 T8389 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd8ac50000, 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> 2425327 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2425329 T8396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d67ec0 name:ZooKeeperConnection Watcher:127.0.0.1:61908 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2425329 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2425330 T8326 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2425336 T8389 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd8ac50001, 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> 2425337 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2425339 T8398 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1932507 name:ZooKeeperConnection Watcher:127.0.0.1:61908/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2425339 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2425339 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2425344 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2425347 T8400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@193ada name:ZooKeeperConnection Watcher:127.0.0.1:61908/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2425347 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2425349 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2425353 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2425360 T8326 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:61908_solr
[junit4] 2> 2425361 T8326 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2425365 T8326 oasc.Overseer.start Overseer (id=91756227645997059-127.0.0.1:61908_solr-n_0000000000) starting
[junit4] 2> 2425369 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2425375 T8326 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2425381 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2425386 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2425391 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2425398 T8326 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2425409 T8402 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2425409 T8326 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2425410 T8401 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2425410 T8402 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:61908_solr
[junit4] 2> 2425414 T8326 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2425416 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2425421 T8326 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2425424 T8404 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aec660 name:ZooKeeperConnection Watcher:127.0.0.1:61908/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2425425 T8326 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2425427 T8326 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2425430 T8326 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 2425439 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2425441 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2425442 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2425442 T8401 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2425442 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2425448 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2425452 T8404 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> 2425452 T8398 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> 2425919 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2425941 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2425950 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2425953 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2425953 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2425960 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2425960 T8401 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2425960 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2425964 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426065 T8398 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> 2426065 T8404 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> 2426433 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2426447 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2426461 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426461 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426461 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426464 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426465 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2426471 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2426471 T8401 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2426471 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2426475 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426575 T8404 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> 2426576 T8398 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> 2426945 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2426965 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 2426977 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426977 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426977 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426982 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2426983 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2426991 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2426991 T8401 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2426991 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2426996 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427098 T8398 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> 2427100 T8404 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> 2427462 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2427475 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427476 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427476 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427477 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2427479 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2427479 T8401 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2427479 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2427485 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427588 T8404 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> 2427589 T8398 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> 2427956 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2427969 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427969 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427969 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2427971 T8401 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2427973 T8401 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2427973 T8401 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2427973 T8401 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2427976 T8400 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2428077 T8398 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> 2428077 T8404 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> 2428449 T8326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2428466 T8389 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd8ac50002, 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> 2428479 T8389 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcd8ac50003, 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> 2428482 T8326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61908 61908
[junit4] 2> 2429915 T8404 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2430647 T8404 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2430652 T8388 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:61908 61908
[junit4] 2> 2430653 T8404 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2430656 T8326 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 2430658 T8401 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:61908_solr
[junit4] 2> 2430660 T8405 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:306)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Oversee
[...truncated too long message...]
2> 2449610 T8728 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 2449610 T8728 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 2449610 T8728 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2449615 T8727 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2449702 T8721 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 2449739 T8716 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fbcde9060000, 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> 2449744 T8326 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62232 62232
[junit4] 2> 2451673 T8715 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62232 62232
[junit4] 2> 2451676 T8326 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 2451676 T8728 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62232_solr
[junit4] 2> 2451678 T8730 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 2451678 T8326 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2451680 T8326 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2454247 T8326 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-E3848C1BF089F548-001
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=en_IE, timezone=America/Chihuahua
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=2,threads=1,free=317800120,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestLMJelinekMercerSimilarityFactory, TestReversedWildcardFilterFactory, AtomicUpdatesTest, TestSolrQueryParser, TestIndexSearcher, URLClassifyProcessorTest, SliceStateTest, TestFieldSortValues, SolrIndexSplitterTest, BlockDirectoryTest, TestCollectionAPI, TestSolrQueryParserDefaultOperatorResource, TestSuggestSpellingConverter, ResourceLoaderTest, TestBadConfig, IndexSchemaRuntimeFieldTest, DeleteInactiveReplicaTest, TestConfig, SolrIndexConfigTest, RequestHandlersTest, TestCloudInspectUtil, SolrPluginUtilsTest, CSVRequestHandlerTest, StressHdfsTest, FieldFacetTest, TestFreeTextSuggestions, UUIDFieldTest, TestUpdate, TestJmxIntegration, HdfsCollectionsAPIDistributedZkTest, XsltUpdateRequestHandlerTest, ResponseLogComponentTest, BJQParserTest, TestMaxScoreQueryParser, TestCloudManagedSchema, CoreAdminCreateDiscoverTest, HdfsUnloadDistributedZkTest, TestStressUserVersions, TestZkChroot, DistanceFunctionTest, CoreAdminRequestStatusTest, TestMultiCoreConfBootstrap, TestDefaultSearchFieldResource, DefaultValueUpdateProcessorTest, NumericFieldsTest, TestManagedSchema, DeleteShardTest, NoFacetTest, PingRequestHandlerTest, ChangedSchemaMergeTest, DocValuesMissingTest, DebugComponentTest, SuggesterWFSTTest, FunctionTest, TestExtendedDismaxParser, DistributedQueryElevationComponentTest, SuggesterFSTTest, LoggingHandlerTest, TestCursorMarkWithoutUniqueKey, SpellPossibilityIteratorTest, SignatureUpdateProcessorFactoryTest, DirectSolrSpellCheckerTest, TestComplexPhraseQParserPlugin, AlternateDirectoryTest, PluginInfoTest, ScriptEngineTest, TestTrie, TestPartialUpdateDeduplication, MBeansHandlerTest, TestFieldTypeCollectionResource, SimplePostToolTest, CircularListTest, TestUtils, QueryResultKeyTest, ClusterStateTest, TestShardHandlerFactory, TestStandardQParsers, HardAutoCommitTest, TestBlendedInfixSuggestions, FieldMutatingUpdateProcessorTest, ShowFileRequestHandlerTest, TestCustomSort, MigrateRouteKeyTest, DistributedExpandComponentTest, MultiTermTest, RangeFacetTest, TestRTGBase, PolyFieldTest, OpenCloseCoreStressTest, HighlighterTest, TestBinaryResponseWriter, CoreAdminHandlerTest, TermsComponentTest, BasicFunctionalityTest, TimeZoneUtilsTest, SuggesterTSTTest, TestQueryTypes, TestSchemaNameResource, TestRequestStatusCollectionAPI, TestXIncludeConfig, TestCSVResponseWriter, TestManagedResourceStorage, DirectSolrConnectionTest, StatsComponentTest, EchoParamsTest, TestStressVersions, TestDistributedMissingSort, TestPseudoReturnFields, CursorPagingTest, TestQuerySenderNoQuery, LeaderElectionIntegrationTest, IndexBasedSpellCheckerTest, TestRestManager, DOMUtilTest, CoreContainerCoreInitFailuresTest, TestJoin, CopyFieldTest, TestReplicationHandler, TestSchemaResource, LeaderElectionTest, HdfsBasicDistributedZk2Test, AutoCommitTest, TestFileDictionaryLookup, DocValuesMultiTest, TestManagedSchemaFieldResource, SolrCoreCheckLockOnStartupTest, ZkNodePropsTest, TestFieldResource, CollectionsAPIAsyncDistributedZkTest, SolrTestCaseJ4Test, TestFiltering, DocumentAnalysisRequestHandlerTest, SimpleFacetsTest, ChaosMonkeySafeLeaderTest, TestNRTOpen, HdfsDirectoryTest, QueryEqualityTest, AsyncMigrateRouteKeyTest, TestDistributedSearch, TestQueryUtils, UpdateParamsTest, TestManagedStopFilterFactory, TestCodecSupport, TestUniqueKeyFieldResource, ZkControllerTest, TestSolrCoreProperties, OpenExchangeRatesOrgProviderTest, OverseerStatusTest, MoreLikeThisHandlerTest, TestNonDefinedSimilarityFactory, AddSchemaFieldsUpdateProcessorFactoryTest, TestRecoveryHdfs, TestDocumentBuilder, TestStressRecovery, FileBasedSpellCheckerTest, TestPerFieldSimilarity, TestSort, TestOverriddenPrefixQueryForCustomFieldType, TestQuerySenderListener, CachingDirectoryFactoryTest, CustomCollectionTest, ShardRoutingTest, TestFieldTypeResource, TestFaceting, SolrXmlInZkTest, SpellingQueryConverterTest, DistributedSpellCheckComponentTest, TestCopyFieldCollectionResource, TestCollationFieldDocValues, TestRealTimeGet, BasicZkTest, TestSearcherReuse, TestModifyConfFiles, ConvertedLegacyTest, UniqFieldsUpdateProcessorFactoryTest, TestStressReorder, TestLazyCores, TestSolrQueryParserResource, SortByFunctionTest, SampleTest, TestPhraseSuggestions, LukeRequestHandlerTest, SSLMigrationTest, FullSolrCloudDistribCmdsTest, TestMiniSolrCloudCluster, TestFastWriter, SolrCoreTest, DistributedQueryComponentCustomSortTest, TestSolrXmlPersistence, AnalysisErrorHandlingTest, TestFieldCollectionResource, TestRemoteStreaming, NoCacheHeaderTest, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, OverseerTest]
[junit4] Completed in 58.57s, 9 tests, 1 error <<< FAILURES!
[...truncated 611 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 400 suites, 1679 tests, 1 error, 42 ignored (21 assumptions)
Total time: 102 minutes 20 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b15 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_60-ea-b15) -
Build # 4035 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4035/
Java: 64bit/jdk1.7.0_60-ea-b15 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([8276D9472455795C:867E56B436F0967D]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
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:360)
at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$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:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 47 more
Build Log:
[...truncated 10999 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-8276D9472455795C-001\init-core-data-001
[junit4] 2> 1439080 T4286 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 1439081 T4286 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1439081 T4286 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1439087 T4286 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 1439091 T4286 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1439093 T4287 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1439218 T4286 oasc.ZkTestServer.run start zk server on port:53160
[junit4] 2> 1439222 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1439232 T4293 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@386eda92 name:ZooKeeperConnection Watcher:127.0.0.1:53160 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1439232 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1439237 T4288 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fb5d40000, 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> 1439239 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1439241 T4295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31eca191 name:ZooKeeperConnection Watcher:127.0.0.1:53160 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1439241 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1439243 T4286 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1439249 T4288 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fb5d40001, 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> 1439250 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1439254 T4297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55edd041 name:ZooKeeperConnection Watcher:127.0.0.1:53160/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1439254 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1439254 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1439260 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1439264 T4299 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@648b7922 name:ZooKeeperConnection Watcher:127.0.0.1:53160/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1439264 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1439267 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1439271 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1439283 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53160_solr
[junit4] 2> 1439283 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1439290 T4286 oasc.Overseer.start Overseer (id=91758161103683587-127.0.0.1:53160_solr-n_0000000000) starting
[junit4] 2> 1439294 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1439302 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1439311 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1439318 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1439327 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1439336 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1439350 T4301 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1439351 T4286 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1439352 T4301 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53160_solr
[junit4] 2> 1439352 T4300 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1439356 T4286 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1439359 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1439368 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1439370 T4303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ac3edcc name:ZooKeeperConnection Watcher:127.0.0.1:53160/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1439372 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1439374 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1439380 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 1439392 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1439396 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1439397 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1439397 T4300 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1439397 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1439404 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1439406 T4303 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> 1439407 T4297 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> 1440015 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1440041 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1440056 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440061 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1440063 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440073 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1440073 T4300 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1440073 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1440078 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440207 T4303 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> 1440209 T4297 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> 1440685 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1440705 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1440718 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440718 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440718 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440723 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440723 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1440733 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1440734 T4300 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1440734 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1440740 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1440870 T4297 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> 1440870 T4303 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> 1441346 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 1441363 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 1441374 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441374 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441374 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441376 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1441384 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441514 T4303 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> 1441514 T4297 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> 1441570 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441570 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441570 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441576 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441577 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1441579 T4300 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1441589 T4300 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 1441597 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441599 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1441599 T4300 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 1441599 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1441605 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1441735 T4303 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> 1441735 T4297 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> 1442206 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 1442228 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 1442241 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442241 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442241 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442246 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442246 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1442255 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1442255 T4300 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1442256 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1442261 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442391 T4297 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> 1442392 T4303 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> 1442869 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 1442886 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 1442897 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442897 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442897 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442902 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1442902 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1442912 T4300 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 1442912 T4300 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 1442912 T4300 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 1442919 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1443048 T4297 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> 1443048 T4303 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> 1443525 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 1443542 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 1443553 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1443553 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1443553 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1443555 T4300 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1443562 T4299 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1443686 T4303 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> 1443686 T4297 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> 1443733 T4288 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fb5d40002, 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> 1443739 T4288 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fb5d40004, 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> 1443743 T4288 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fb5d40003, 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> 1443744 T4286 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53160 53160
[junit4] 2> 1446271 T4287 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53160 53160
[junit4] 2> 1446274 T4286 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 1446275 T4300 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53160_solr
[junit4] 2> 1446277 T4304 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 1446283 T4286 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 1446286 T4286 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1446287 T4305 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1446400 T4286 oasc.ZkTestServer.run start zk server on port:53178
[junit4] 2> 1446403 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1446412 T4311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c207d42 name:ZooKeeperConnection Watcher:127.0.0.1:53178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1446413 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1446418 T4306 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fd1ec0000, 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> 1446419 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1446422 T4313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e1ef640 name:ZooKeeperConnection Watcher:127.0.0.1:53178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1446422 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1446423 T4286 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1446431 T4306 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fd1ec0001, 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> 1446434 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1446437 T4315 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52319c1f name:ZooKeeperConnection Watcher:127.0.0.1:53178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1446437 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1446437 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1446445 T4286 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1446450 T4286 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1446455 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1446461 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1446465 T4317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41ab6832 name:ZooKeeperConnection Watcher:127.0.0.1:53178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1446466 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1446467 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1446472 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1446479 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1446482 T4319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32bfa549 name:ZooKeeperConnection Watcher:127.0.0.1:53178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1446482 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1446483 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1446488 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1446496 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53178_solr
[junit4] 2> 1446496 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1446502 T4286 oasc.Overseer.start Overseer (id=91758161575018500-127.0.0.1:53178_solr-n_0000000000) starting
[junit4] 2> 1446506 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1446513 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1446519 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1446526 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1446534 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1446540 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1446552 T4321 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1446554 T4321 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53178_solr
[junit4] 2> 1446554 T4320 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1447679 T4319 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1447682 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1447685 T4320 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> 1447685 T4320 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1447685 T4320 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1447692 T4319 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1447694 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1447694 T4315 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> 1448239 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1448259 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1448271 T4319 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1448272 T4286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1448274 T4320 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1448281 T4319 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1448281 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1448284 T4320 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> 1448285 T4320 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1448291 T4319 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1448409 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1448410 T4315 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> 1449598 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1449614 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1449619 T4323 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43024ad7 name:ZooKeeperConnection Watcher:127.0.0.1:53178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1449619 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1449620 T4320 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53178_solr
[junit4] 2> 1449623 T4324 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 1449632 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53178_solr
[junit4] 2> 1449633 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1449637 T4286 oasc.Overseer.start Overseer (id=91758161575018501-127.0.0.1:53178_solr-n_0000000001) starting
[junit4] 2> 1449668 T4326 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1449669 T4326 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53178_solr
[junit4] 2> 1449669 T4325 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1449672 T4325 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1449675 T4325 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> 1449675 T4325 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1449679 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449681 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1449681 T4315 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> 1449746 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449746 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1449748 T4325 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1449759 T4317 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1449762 T4286 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91758161575018499-node1_core1-n_0000000001
[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:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[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:360)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
[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:360)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1449764 T4325 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:1066)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:346)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:242)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 1449768 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1449771 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449775 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449779 T4317 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1449779 T4325 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1449785 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449793 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449797 T4325 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 1449803 T4323 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1449920 T4317 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1449921 T4315 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> 1450899 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1452028 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1453157 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1454285 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1455356 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1456371 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1457386 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1458402 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1459417 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1460432 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1461446 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1462461 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1463476 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1464491 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1465448 T4286 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1465461 T4306 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd8fd1ec0003, 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> 1465468 T4286 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53178 53178
[junit4] 2> 1467515 T4305 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53178 53178
[junit4] 2> 1467518 T4286 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 1467518 T4325 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53178_solr
[junit4] 2> 1467520 T4327 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:306)
[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:289)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=8276D9472455795C -Dtests.slow=true -Dtests.locale=da -Dtests.timezone=America/Kralendijk -Dtests.file.encoding=US-ASCII
[junit4] ERROR 21.3s | 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([8276D9472455795C:867E56B436F0967D]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$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:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > ... 47 more
[junit4] 2> 1467541 T4286 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 1467543 T4286 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1467544 T4328 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1467634 T4286 oasc.ZkTestServer.run start zk server on port:53199
[junit4] 2> 1467635 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1467640 T4334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6961951e name:ZooKeeperConnection Watcher:127.0.0.1:53199/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1467640 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1467642 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1467645 T4336 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1466133a name:ZooKeeperConnection Watcher:127.0.0.1:53199 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1467645 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1467647 T4329 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd9024f40001, 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> 1467649 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1467652 T4338 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e280469 name:ZooKeeperConnection Watcher:127.0.0.1:53199 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1467653 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1467653 T4286 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1467657 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1467657 T4329 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd9024f40002, 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> 1467661 T4286 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1467664 T4286 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1467668 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1467673 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1467675 T4340 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41dc829e name:ZooKeeperConnection Watcher:127.0.0.1:53199/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1467676 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1467677 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1467680 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1467688 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53199_solr
[junit4] 2> 1467688 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1467692 T4286 oasc.Overseer.start Overseer (id=91758162968051715-127.0.0.1:53199_solr-n_0000000000) starting
[junit4] 2> 1467694 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1467699 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1467704 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1467709 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1467714 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1467719 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1467727 T4342 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1467729 T4342 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53199_solr
[junit4] 2> 1467730 T4341 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1467732 T4286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1467733 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1467733 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1467733 T4341 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1467738 T4340 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1467739 T4334 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1467780 T4286 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1467782 T4340 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1467785 T4341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1467786 T4341 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 1467786 T4341 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 1467786 T4341 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1467791 T4340 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1467885 T4334 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1467938 T4286 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53199 53199
[junit4] 2> 1469987 T4328 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53199 53199
[junit4] 2> 1469989 T4286 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 1469989 T4341 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53199_solr
[junit4] 2> 1469991 T4343 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 1469997 T4286 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 1469997 T4286 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1469998 T4344 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1470089 T4286 oasc.ZkTestServer.run start zk server on port:53214
[junit4] 2> 1470091 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1470095 T4350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6cc711c8 name:ZooKeeperConnection Watcher:127.0.0.1:53214/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1470096 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1470097 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1470098 T4352 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15f3ee67 name:ZooKeeperConnection Watcher:127.0.0.1:53214 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1470099 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1470101 T4345 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd902e8d0001, 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> 1470102 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1470105 T4354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c4ae753 name:ZooKeeperConnection Watcher:127.0.0.1:53214 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1470105 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1470105 T4286 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1470109 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1470109 T4345 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd902e8d0002, 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> 1470113 T4286 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1470117 T4286 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1470121 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1470128 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1470136 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1470139 T4356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48c677be name:ZooKeeperConnection Watcher:127.0.0.1:53214/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1470139 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1470141 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1470145 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1470152 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53214_solr
[junit4] 2> 1470152 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1470155 T4286 oasc.Overseer.start Overseer (id=91758163129073667-127.0.0.1:53214_solr-n_0000000000) starting
[junit4] 2> 1470158 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1470164 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1470169 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1470174 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1470179 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1470188 T4358 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1470190 T4358 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53214_solr
[junit4] 2> 1470193 T4357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1470194 T4357 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1470195 T4357 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1470197 T4350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1470207 T4357 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1470208 T4350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1470213 T4357 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1470217 T4357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1470219 T4357 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1470224 T4356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1470318 T4350 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1470376 T4345 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd902e8d0003, 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> 1470379 T4345 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd902e8d0000, 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> 1470379 T4286 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53214 53214
[junit4] 2> 1472429 T4344 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:53214 53214
[junit4] 2> 1472433 T4286 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 1472434 T4357 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53214_solr
[junit4] 2> 1472437 T4360 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 1472450 T4286 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 1472456 T4286 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1472456 T4361 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1472548 T4286 oasc.ZkTestServer.run start zk server on port:53230
[junit4] 2> 1472550 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1472562 T4367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a83b5ae name:ZooKeeperConnection Watcher:127.0.0.1:53230/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472563 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1472566 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1472570 T4369 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6286cc09 name:ZooKeeperConnection Watcher:127.0.0.1:53230 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472571 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1472577 T4362 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd9038280001, 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> 1472579 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1472586 T4371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e35ceb9 name:ZooKeeperConnection Watcher:127.0.0.1:53230 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472587 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1472587 T4286 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1472598 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1472599 T4362 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145fd9038280002, 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> 1472607 T4286 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1472616 T4286 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1472623 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1472634 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1472638 T4373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48559732 name:ZooKeeperConnection Watcher:127.0.0.1:53230/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472639 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1472643 T4286 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1472651 T4286 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1472663 T4286 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1472668 T4375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@277f7157 name:ZooKeeperConnection Watcher:127.0.0.1:53230/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1472669 T4286 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1472671 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1472679 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1472693 T4286 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53230_solr
[junit4] 2> 1472693 T4286 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1472701 T4286 oasc.Overseer.start Overseer (id=91758163290226692-127.0.0.1:53230_solr-n_0000000000) starting
[junit4] 2> 1472709 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1472721 T4286 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1472733 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1472747 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1472761 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1472775 T4286 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1472797 T4377 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1472800 T4377 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:53230_solr
[junit4] 2> 1472804 T4376 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1472810 T4376 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1472812 T4376 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> 1472813 T4376 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1472813 T4376 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1472825 T4375 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1472829 T4373 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> 1472830
[...truncated too long message...]
472)
[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.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1495591 T4714 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java: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.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1495592 T4286 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 1495594 T4711 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:53566_solr
[junit4] 2> 1495595 T4715 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:306)
[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:289)
[junit4] 2>
[junit4] 2> 1495595 T4286 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1495597 T4286 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1498064 T4286 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-8276D9472455795C-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=DefaultSimilarity, locale=da, timezone=America/Kralendijk
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=146648688,total=385933312
[junit4] 2> NOTE: All tests run in this JVM: [TestArbitraryIndexDir, CustomCollectionTest, SuggesterTSTTest, TestCollationField, TestManagedStopFilterFactory, ConvertedLegacyTest, HdfsDirectoryTest, TestCustomSort, QueryFacetTest, TestRestManager, SpellingQueryConverterTest, TestStandardQParsers, DocValuesTest, TestExtendedDismaxParser, TestImplicitCoreProperties, TestStressLucene, AlternateDirectoryTest, CoreMergeIndexesAdminHandlerTest, QueryParsingTest, CoreAdminRequestStatusTest, HdfsUnloadDistributedZkTest, XmlUpdateRequestHandlerTest, TestBinaryField, ExpressionTest, SolrCmdDistributorTest, TestCSVLoader, TestCSVResponseWriter, JsonLoaderTest, TestRecoveryHdfs, CachingDirectoryFactoryTest, TestDynamicFieldCollectionResource, TestTrie, TestFastWriter, TestCollationFieldDocValues, CurrencyFieldOpenExchangeTest, UUIDFieldTest, TestBinaryResponseWriter, ReturnFieldsTest, FieldMutatingUpdateProcessorTest, BJQParserTest, AutoCommitTest, SpellPossibilityIteratorTest, TestSuggestSpellingConverter, TestUniqueKeyFieldResource, DocumentBuilderTest, SoftAutoCommitTest, ShardSplitTest, TestCharFilters, CoreAdminHandlerTest, TestWordDelimiterFilterFactory, UnloadDistributedZkTest, TestStressRecovery, HdfsBasicDistributedZk2Test, TestSerializedLuceneMatchVersion, CursorPagingTest, ScriptEngineTest, PrimUtilsTest, RegexBoostProcessorTest, TestLFUCache, TestCursorMarkWithoutUniqueKey, TestNonNRTOpen, HdfsWriteToMultipleCollectionsTest, TestHighlightDedupGrouping, SpatialFilterTest, TestPseudoReturnFields, SchemaVersionSpecificBehaviorTest, DirectSolrConnectionTest, TestAddFieldRealTimeGet, OverseerStatusTest, TestDynamicFieldResource, ChangedSchemaMergeTest, TestRealTimeGet, TestFaceting, DirectSolrSpellCheckerTest, TestSolrXmlPersistor, TestSolr4Spatial, ParsingFieldUpdateProcessorsTest, TestQuerySenderListener, TestRandomDVFaceting, TestBadConfig, SuggesterTest, MultiTermTest, TestConfig, TestFunctionQuery, SOLR749Test, ZkCLITest, ModifyConfFileTest, SolrTestCaseJ4Test, PeerSyncTest, TestMiniSolrCloudCluster, TestSchemaVersionResource, TestComponentsName, TestStressUserVersions, IndexSchemaRuntimeFieldTest, RankQueryTest, SpellCheckComponentTest, TestDefaultSimilarityFactory, BasicZkTest, LoggingHandlerTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrXmlPersistence, TestShortCircuitedRequests, TestSolrQueryParser, TestAnalyzeInfixSuggestions, DistributedTermsComponentTest, CoreAdminCreateDiscoverTest, TestQueryTypes, EchoParamsTest, InfoHandlerTest, URLClassifyProcessorTest, TestZkChroot, SolrXmlInZkTest, TestFuzzyAnalyzedSuggestions, DistributedSuggestComponentTest, TestSolrIndexConfig, TestExceedMaxTermLength, TestNoOpRegenerator, UpdateRequestProcessorFactoryTest, BlockDirectoryTest, TestLMDirichletSimilarityFactory, TestBlendedInfixSuggestions, AbstractAnalyticsStatsTest, BasicFunctionalityTest, LukeRequestHandlerTest, SimpleFacetsTest, TestDocSet, TestRequestStatusCollectionAPI, BasicDistributedZk2Test, ShardRoutingCustomTest, SuggesterWFSTTest, FieldAnalysisRequestHandlerTest, HighlighterConfigTest, OverseerRolesTest, StressHdfsTest, MoreLikeThisHandlerTest, TestCloudManagedSchemaAddField, RequiredFieldsTest, DirectUpdateHandlerOptimizeTest, FieldFacetExtrasTest, DocExpirationUpdateProcessorFactoryTest, TestNRTOpen, PrimitiveFieldTypeTest, TestJmxMonitoredMap, TestRTGBase, TestCodecSupport, TestExpandComponent, TestFieldCollectionResource, SolrInfoMBeanTest, OverseerCollectionProcessorTest, TestMergePolicyConfig, ZkNodePropsTest, RAMDirectoryFactoryTest, SortByFunctionTest, TestReversedWildcardFilterFactory, ZkSolrClientTest, DistributedDebugComponentTest, DocValuesMultiTest, DeleteInactiveReplicaTest, TestClassNameShortening, BlockCacheTest, TestManagedResourceStorage, ShardRoutingTest, AddSchemaFieldsUpdateProcessorFactoryTest, CircularListTest, LeaderElectionIntegrationTest, EnumFieldTest, JSONWriterTest, HardAutoCommitTest, SliceStateTest, TestFieldSortValues, BadIndexSchemaTest, TestConfigSets, TestLazyCores, TestPartialUpdateDeduplication, OverseerTest]
[junit4] Completed in 59.05s, 9 tests, 1 error <<< FAILURES!
[...truncated 694 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1296: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:920: There were test failures: 403 suites, 1681 tests, 1 error, 42 ignored (21 assumptions)
Total time: 98 minutes 26 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b15 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure