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/06/01 09:19:53 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_60-ea-b15) -
Build # 3991 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3991/
Java: 64bit/jdk1.7.0_60-ea-b15 -XX:-UseCompressedOops -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([6FBE86486F0FD511:6BB609BB7DAA3A30]: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.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 47 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 48 more
Build Log:
[...truncated 11386 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-6FBE86486F0FD511-001\init-core-data-001
[junit4] 2> 2589070 T7723 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 2589070 T7723 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2589070 T7723 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2589074 T7723 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 2589076 T7723 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2589077 T7724 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2589168 T7723 oasc.ZkTestServer.run start zk server on port:64989
[junit4] 2> 2589169 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589175 T7730 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e953cf1 name:ZooKeeperConnection Watcher:127.0.0.1:64989/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589175 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589176 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589179 T7732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14c587ec name:ZooKeeperConnection Watcher:127.0.0.1:64989 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589179 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589183 T7725 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630b79e0001, 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> 2589184 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589186 T7734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ec714c2 name:ZooKeeperConnection Watcher:127.0.0.1:64989 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589187 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589187 T7723 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2589192 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2589192 T7725 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630b79e0002, 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> 2589197 T7723 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2589200 T7723 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2589203 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2589209 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589211 T7736 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7692c255 name:ZooKeeperConnection Watcher:127.0.0.1:64989/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589212 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589213 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2589216 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2589221 T7730 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2589221 T7736 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2589223 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589226 T7738 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5755013a name:ZooKeeperConnection Watcher:127.0.0.1:64989/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589226 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589227 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2589230 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2589266 T7723 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:64989_solr
[junit4] 2> 2589266 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2589270 T7723 oasc.Overseer.start Overseer (id=91855609646678020-127.0.0.1:64989_solr-n_0000000000) starting
[junit4] 2> 2589273 T7723 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2589277 T7723 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2589282 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2589287 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2589291 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2589297 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2589304 T7740 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2589306 T7739 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2589308 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589311 T7739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2589311 T7739 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> 2589311 T7739 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2589311 T7739 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2589315 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589316 T7736 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> 2589317 T7730 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> 2589761 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2589775 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2589782 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589784 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2589785 T7739 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2589786 T7730 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2589787 T7736 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2589790 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2589792 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589793 T7742 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ea9620b name:ZooKeeperConnection Watcher:127.0.0.1:64989/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2589794 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2589795 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2589797 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2589801 T7730 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2589802 T7742 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2589805 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589805 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2589806 T7739 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> 2589806 T7739 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2589810 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589813 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2589819 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589824 T7738 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2589917 T7730 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> 2589917 T7742 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> 2589918 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2589922 T7725 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630b79e0004, 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> 2589923 T7730 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2589924 T7742 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2589926 T7725 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630b79e0000, 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> 2589926 T7723 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:64989 64989
[junit4] 2> 2591035 T7740 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2591178 T7739 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:180)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:592)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:267)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2591798 T7739 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:64989_solr
[junit4] 2> 2591797 T7724 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:64989 64989
[junit4] 2> 2591800 T7743 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:302)
[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:291)
[junit4] 2>
[junit4] 2> 2591802 T7723 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 2> 2591806 T7723 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 2591807 T7723 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2591808 T7744 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2591890 T7723 oasc.ZkTestServer.run start zk server on port:65010
[junit4] 2> 2591891 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2591895 T7750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b227a37 name:ZooKeeperConnection Watcher:127.0.0.1:65010 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2591896 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2591899 T7745 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630c24a0000, 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> 2591900 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2591902 T7752 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e231d02 name:ZooKeeperConnection Watcher:127.0.0.1:65010 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2591903 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2591903 T7723 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2591907 T7745 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630c24a0001, 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> 2591908 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2591910 T7754 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f318845 name:ZooKeeperConnection Watcher:127.0.0.1:65010/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2591910 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2591910 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2591914 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2591915 T7756 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@246315f4 name:ZooKeeperConnection Watcher:127.0.0.1:65010/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2591916 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2591917 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2591919 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2591924 T7723 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65010_solr
[junit4] 2> 2591924 T7723 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2591926 T7723 oasc.Overseer.start Overseer (id=91855609825722371-127.0.0.1:65010_solr-n_0000000000) starting
[junit4] 2> 2591929 T7723 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2591933 T7723 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2591937 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2591941 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2591945 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2591949 T7723 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2591956 T7758 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2591957 T7723 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2591957 T7757 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2591958 T7723 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2591961 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2591965 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2591966 T7760 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29546989 name:ZooKeeperConnection Watcher:127.0.0.1:65010/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2591966 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2591968 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2591970 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 2591973 T7760 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2591974 T7754 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2591976 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2591978 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2591979 T7757 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> 2591979 T7757 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2591979 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2591983 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2591984 T7760 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> 2591984 T7754 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> 2592383 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2592396 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 2592404 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592407 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592407 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2592412 T7757 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> 2592412 T7757 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2592412 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2592416 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592500 T7754 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> 2592501 T7760 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> 2592814 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2592825 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2592834 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592834 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592834 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592837 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592837 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2592843 T7757 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> 2592843 T7757 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2592843 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2592847 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2592930 T7760 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> 2592931 T7754 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> 2593244 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2593254 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2593260 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593260 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593260 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593262 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2593266 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593351 T7754 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> 2593352 T7760 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> 2593388 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593388 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593388 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593391 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593391 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2593392 T7757 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> 2593397 T7757 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> 2593400 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593401 T7757 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> 2593401 T7757 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 2593401 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2593405 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593490 T7760 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> 2593490 T7754 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> 2593800 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 2593810 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 2593817 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593817 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593817 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593820 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593820 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2593825 T7757 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> 2593825 T7757 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2593825 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2593828 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2593912 T7754 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> 2593913 T7760 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> 2594227 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 2594240 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 2594247 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594247 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594247 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594250 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594250 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2594255 T7757 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> 2594255 T7757 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2594255 T7757 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2594259 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594343 T7760 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> 2594344 T7754 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> 2594657 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 2594667 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 2594674 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594674 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594674 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594676 T7757 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2594680 T7756 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2594764 T7754 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> 2594764 T7760 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> 2594802 T7760 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2594804 T7745 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630c24a0004, 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> 2594806 T7723 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65010 65010
[junit4] 2> 2595216 T7758 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2596641 T7744 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65010 65010
[junit4] 2> 2596644 T7723 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 2596645 T7757 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:65010_solr
[junit4] 2> 2596647 T7761 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:302)
[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:291)
[junit4] 2>
[junit4] 2> 2596650 T7723 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2596653 T7723 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2596654 T7762 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2596736 T7723 oasc.ZkTestServer.run start zk server on port:65028
[junit4] 2> 2596737 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596742 T7768 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58b9a1db name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596743 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596744 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596747 T7770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6697602b name:ZooKeeperConnection Watcher:127.0.0.1:65028 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596747 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596752 T7763 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630d5380001, 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> 2596754 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596756 T7772 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24c7ae20 name:ZooKeeperConnection Watcher:127.0.0.1:65028 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596757 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596757 T7723 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2596762 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2596762 T7763 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630d5380002, 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> 2596771 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596771 T7773 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596774 T7776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c412bf1 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596774 T7773 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596774 T7777 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@496518d4 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596775 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596775 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2596776 T7723 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2596780 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2596780 T7723 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2596783 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2596787 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2596788 T7773 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65028_solr
[junit4] 2> 2596789 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2596792 T7777 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2596794 T7773 oasc.Overseer.start Overseer (id=91855610143309827-127.0.0.1:65028_solr-n_0000000000) starting
[junit4] 2> 2596794 T7723 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2596802 T7773 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2596806 T7773 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2596812 T7773 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2596817 T7773 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2596824 T7773 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2596833 T7773 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2596833 T7779 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2596836 T7763 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1465630d5380003, 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> 2596836 T7778 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:98)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:140)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:361)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:143)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2596838 T7773 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2596841 T7781 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@779ea7e4 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2596841 T7773 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2596842 T7779 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91855610143309827-127.0.0.1:65028_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2596842 T7779 oasc.SolrException.log ERROR :org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/collection-queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:98)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.getTailId(DistributedQueue.java:450)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:245)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2596843 T7779 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:412)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:260)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 2596848 T7773 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65028_solr
[junit4] 2> 2596848 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2596851 T7773 oasc.Overseer.start Overseer (id=91855610143309829-127.0.0.1:65028_solr-n_0000000001) starting
[junit4] 2> 2596871 T7783 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2596872 T7782 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2596875 T7782 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2596876 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2596876 T7782 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2596876 T7782 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2596882 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2596883 T7777 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> 2597208 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2597221 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2597230 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597232 T7782 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597234 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597234 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2597240 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2597241 T7782 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2597246 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597248 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2597250 T7785 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b5e45d9 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2597251 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2597251 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2597255 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2597259 T7777 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2597260 T7785 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2597263 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597263 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2597266 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2597266 T7782 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2597270 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597274 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597355 T7785 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2597355 T7777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2597440 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597444 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597444 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597444 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597445 T7782 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597446 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2597446 T7782 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2597446 T7782 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2597451 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597535 T7777 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2597535 T7785 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2597851 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2597862 T7777 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2597863 T7785 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2597864 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597866 T7785 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2597874 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597874 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597874 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597876 T7782 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2597881 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2597966 T7785 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> 2598029 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598030 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598033 T7787 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fef0087 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598034 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598035 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2598038 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2598043 T7787 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598043 T7785 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598046 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598046 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598047 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598047 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598050 T7782 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598051 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598052 T7782 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598059 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598059 T7787 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2598062 T7787 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2598063 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598064 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598065 T7782 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598066 T7782 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598072 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598075 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598081 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598084 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598084 T7789 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76b50a14 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598084 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598086 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2598089 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2598093 T7787 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598094 T7789 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598096 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598097 T7781 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598098 T7773 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2598103 T7773 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598104 T7791 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ffc9ea4 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598105 T7773 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598106 T7782 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:65028_solr
[junit4] 2> 2598108 T7792 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:302)
[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:291)
[junit4] 2>
[junit4] 2> 2598112 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598114 T7773 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65028_solr
[junit4] 2> 2598114 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2598117 T7773 oasc.Overseer.start Overseer (id=91855610143309833-127.0.0.1:65028_solr-n_0000000002) starting
[junit4] 2> 2598138 T7794 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2598143 T7793 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598143 T7793 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2598144 T7793 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598144 T7793 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598146 T7789 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598146 T7787 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598150 T7793 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598150 T7793 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598152 T7787 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598152 T7789 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598158 T7787 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598158 T7789 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598162 T7793 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2598164 T7793 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598165 T7793 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598165 T7793 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598169 T7791 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598170 T7789 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598170 T7787 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2598278 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598282 T7791 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598282 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598285 T7793 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598286 T7793 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2598286 T7793 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598292 T7791 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598294 T7787 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2598295 T7789 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2598297 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598298 T7789 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2598305 T7791 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598310 T7791 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598394 T7789 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> 2598458 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598461 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598461 T7773 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2598462 T7796 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fff103e name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598463 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598466 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2598466 T7773 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598468 T7798 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cf64a00 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598468 T7773 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598470 T7793 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:65028_solr
[junit4] 2> 2598471 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2598472 T7799 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:302)
[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:291)
[junit4] 2>
[junit4] 2> 2598477 T7773 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:65028_solr
[junit4] 2> 2598478 T7796 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598478 T7789 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598478 T7773 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2598480 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598481 T7773 oasc.Overseer.start Overseer (id=91855610143309835-127.0.0.1:65028_solr-n_0000000003) starting
[junit4] 2> 2598491 T7796 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2598493 T7796 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2598495 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598504 T7801 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2598506 T7800 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2598507 T7723 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2598509 T7803 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13b61b30 name:ZooKeeperConnection Watcher:127.0.0.1:65028/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2598510 T7723 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2598511 T7800 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598511 T7800 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598512 T7800 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598511 T7723 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2598516 T7798 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598516 T7723 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2598517 T7796 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> 2598517 T7803 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2598521 T7803 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598522 T7796 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2598526 T7723 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2598528 T7800 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598529 T7800 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2598529 T7800 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2598533 T7798 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598536 T7723 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2598537 T7798 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2598539 T7800 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"
[...truncated too long message...]
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 2632351 T8178 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2632352 T8172 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> 2632417 T8167 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14656315fd20003, 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> 2632421 T8167 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14656315fd20000, 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> 2632421 T7723 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65427 65427
[junit4] 2> 2634084 T8180 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 2634402 T8166 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65427 65427
[junit4] 2> 2634403 T7723 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 2634403 T8179 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:65427_solr
[junit4] 2> 2634404 T8181 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:302)
[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:291)
[junit4] 2>
[junit4] 2> 2634404 T7723 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2634406 T7723 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2637134 T7723 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-6FBE86486F0FD511-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=DefaultSimilarity, locale=en_NZ, timezone=GB-Eire
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=354963064,total=511705088
[junit4] 2> NOTE: All tests run in this JVM: [DeleteInactiveReplicaTest, TestConfigSets, ChaosMonkeySafeLeaderTest, SolrIndexSplitterTest, OverseerStatusTest, TestSolrXmlPersistence, TestDocBasedVersionConstraints, DirectUpdateHandlerTest, TestStressVersions, TestNonNRTOpen, TestMiniSolrCloudCluster, JSONWriterTest, XsltUpdateRequestHandlerTest, TestBinaryResponseWriter, TestManagedSchemaFieldResource, TestSimpleQParserPlugin, CurrencyFieldXmlFileTest, TestBinaryField, TestPhraseSuggestions, TestExpandComponent, MultiThreadedOCPTest, TestNumberUtils, TestNonDefinedSimilarityFactory, RecoveryZkTest, OverseerRolesTest, TestAddFieldRealTimeGet, TermVectorComponentDistributedTest, TestQueryTypes, DistributedQueryComponentCustomSortTest, DocumentAnalysisRequestHandlerTest, BasicDistributedZk2Test, RankQueryTest, UniqFieldsUpdateProcessorFactoryTest, TestNoOpRegenerator, TestRecoveryHdfs, SynonymTokenizerTest, NotRequiredUniqueKeyTest, HdfsDirectoryTest, IndexSchemaTest, TestMergePolicyConfig, FastVectorHighlighterTest, TestStressUserVersions, TestSolrCoreProperties, TestDocSet, TestSolrXmlPersistor, BasicFunctionalityTest, TestFastOutputStream, ZkSolrClientTest, TestSystemIdResolver, PreAnalyzedFieldTest, LeaderElectionTest, AutoCommitTest, TestElisionMultitermQuery, ShardSplitTest, RequestHandlersTest, TestCharFilters, CoreAdminRequestStatusTest, TestUpdate, FullSolrCloudDistribCmdsTest, TestSolrDeletionPolicy1, TestLuceneMatchVersion, TestConfig, TimeZoneUtilsTest, TestComponentsName, DirectSolrConnectionTest, XmlUpdateRequestHandlerTest, LoggingHandlerTest, LegacyHTMLStripCharFilterTest, AssignTest, SOLR749Test, OverseerCollectionProcessorTest, SimplePostToolTest, TestManagedSynonymFilterFactory, WordBreakSolrSpellCheckerTest, HdfsSyncSliceTest, TestManagedResource, RequiredFieldsTest, TestDistributedGrouping, TestHighFrequencyDictionaryFactory, TestValueSourceCache, TestMaxScoreQueryParser, AddSchemaFieldsUpdateProcessorFactoryTest, HdfsUnloadDistributedZkTest, NumericFieldsTest, HighlighterTest, BlockCacheTest, BadIndexSchemaTest, ShowFileRequestHandlerTest, TestRandomFaceting, SuggesterTest, BadComponentTest, TestRangeQuery, SolrCoreCheckLockOnStartupTest, TestSearcherReuse, TestFuzzyAnalyzedSuggestions, StandardRequestHandlerTest, HttpPartitionTest, TestAtomicUpdateErrorCases, TestManagedStopFilterFactory, FileUtilsTest, DistributedTermsComponentTest, TestMultiCoreConfBootstrap, SpellCheckCollatorTest, TestDynamicFieldCollectionResource, BasicZkTest, TestReversedWildcardFilterFactory, TestIBSimilarityFactory, TestCollectionAPI, TestGroupingSearch, TestIndexSearcher, SyncSliceTest, ZkControllerTest, TestSerializedLuceneMatchVersion, TestCollationField, TestRandomDVFaceting, SolrCmdDistributorTest, CoreAdminHandlerTest, SuggesterFSTTest, TestCoreContainer, ClusterStateTest, TestClassNameShortening, TestFieldTypeCollectionResource, CursorPagingTest, CursorMarkTest, SolrPluginUtilsTest, TestDFRSimilarityFactory, TestSweetSpotSimilarityFactory, MigrateRouteKeyTest, CollectionsAPIDistributedZkTest, DistributedSuggestComponentTest, TestPostingsSolrHighlighter, TestDistributedSearch, MoreLikeThisHandlerTest, BlockDirectoryTest, ResponseLogComponentTest, TestSolrDeletionPolicy2, SuggesterWFSTTest, DateMathParserTest, ResourceLoaderTest, RemoteQueryErrorTest, TestComplexPhraseQParserPlugin, TestCursorMarkWithoutUniqueKey, CoreMergeIndexesAdminHandlerTest, HdfsChaosMonkeySafeLeaderTest, SolrXmlInZkTest, TestSolrXMLSerializer, TestIndexingPerformance, AsyncMigrateRouteKeyTest, TestRecovery, SuggestComponentTest, TestHashPartitioner, QueryResultKeyTest, TestFieldCollectionResource, TestCollapseQParserPlugin, TestDistribDocBasedVersion, TestFileDictionaryLookup, TestShortCircuitedRequests, TestSolrQueryParserResource, TestSchemaVersionResource, QueryEqualityTest, OpenExchangeRatesOrgProviderTest, HdfsLockFactoryTest, TestReload, DOMUtilTest, ConnectionManagerTest, TestOmitPositions, TestBM25SimilarityFactory, TestFoldingMultitermQuery, TestSchemaResource, TestCopyFieldCollectionResource, SolrInfoMBeanTest, AtomicUpdatesTest, CSVRequestHandlerTest, TestFieldTypeResource, TestStressLucene, SpatialFilterTest, TestAnalyzeInfixSuggestions, HighlighterConfigTest, TestReloadAndDeleteDocs, EnumFieldTest, DocExpirationUpdateProcessorFactoryTest, MBeansHandlerTest, OpenCloseCoreStressTest, DistributedQueryComponentOptimizationTest, DistributedDebugComponentTest, FileBasedSpellCheckerTest, ChaosMonkeyNothingIsSafeTest, TestSuggestSpellingConverter, UpdateParamsTest, TestCollationKeyRangeQueries, TestFaceting, BasicDistributedZkTest, UnloadDistributedZkTest, OverseerTest]
[junit4] Completed in 48.09s, 9 tests, 1 error <<< FAILURES!
[...truncated 614 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1297: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 error, 41 ignored (20 assumptions)
Total time: 107 minutes 24 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b15 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure