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/08/25 06:12:02 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1789
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1789/
Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
at __randomizedtesting.SeedInfo.seed([A601EA9ABB719A1A:A2096569A9D4753B]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:291)
at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:288)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:288)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10769 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-A601EA9ABB719A1A-001/init-core-data-001
[junit4] 2> 245145 T78 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 245146 T78 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 245146 T78 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 245162 T78 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 245186 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 245202 T79 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 245742 T78 oasc.ZkTestServer.run start zk server on port:49209
[junit4] 2> 246147 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 246456 T80 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
[junit4] 2> 248063 T84 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46678bc6 name:ZooKeeperConnection Watcher:127.0.0.1:49209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 248064 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 248072 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 248079 T87 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36fef6e6 name:ZooKeeperConnection Watcher:127.0.0.1:49209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 248079 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 248149 T80 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1480aff3c8a0001, 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> 248153 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 248177 T89 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3df57dbb name:ZooKeeperConnection Watcher:127.0.0.1:49209 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 248178 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 248191 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 248259 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 248260 T80 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1480aff3c8a0002, 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> 248286 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 248295 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 248304 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 248387 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 248392 T91 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a62f9e2 name:ZooKeeperConnection Watcher:127.0.0.1:49209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 248392 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 248397 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 248406 T78 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 248435 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 248439 T95 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c25c61 name:ZooKeeperConnection Watcher:127.0.0.1:49209/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 248440 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 248440 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 248462 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 248476 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 248485 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 248517 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49209_solr
[junit4] 2> 248523 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 248557 T78 oasc.Overseer.start Overseer (id=92335883709710340-127.0.0.1:49209_solr-n_0000000000) starting
[junit4] 2> 248597 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 248611 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 248634 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 248646 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 248660 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 248710 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 248744 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 249351 T97 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 249372 T96 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 249402 T96 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 249402 T96 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 249450 T96 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 249469 T99 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 249486 T93 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> 249486 T92 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> 249871 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 249933 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 249957 T99 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 250014 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49209 49209
[junit4] 2> 250038 T79 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49209 49209
[junit4] 2> 250254 T78 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 2> 250255 T78 oasc.Overseer.close Overseer (id=92335883709710340-127.0.0.1:49209_solr-n_0000000000) closing
[junit4] 2> 250256 T96 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49209_solr
[junit4] 2> 250268 T100 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 250304 T78 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 250306 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 250307 T101 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 250408 T78 oasc.ZkTestServer.run start zk server on port:49216
[junit4] 2> 250410 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 250426 T107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35e02a9b name:ZooKeeperConnection Watcher:127.0.0.1:49216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 250427 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 250430 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 250437 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b13d0f4 name:ZooKeeperConnection Watcher:127.0.0.1:49216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 250437 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 250444 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 250449 T111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@550ba701 name:ZooKeeperConnection Watcher:127.0.0.1:49216 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 250450 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 250450 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 250470 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 250495 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 250503 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 250511 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 250522 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 250535 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 250545 T113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b8f30fc name:ZooKeeperConnection Watcher:127.0.0.1:49216/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 250545 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 250545 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 250550 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 250557 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 250576 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 250601 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49216_solr
[junit4] 2> 250601 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 250607 T78 oasc.Overseer.start Overseer (id=92335883997216771-127.0.0.1:49216_solr-n_0000000000) starting
[junit4] 2> 250621 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 250646 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 250662 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 250673 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 250683 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 250715 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 250718 T115 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 250734 T114 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 250736 T114 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 250742 T117 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> 250761 T114 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 250765 T117 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> 250774 T114 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 250784 T114 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 250790 T118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 250794 T117 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> 250845 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49216 49216
[junit4] 2> 250858 T101 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49216 49216
[junit4] 2> 251092 T78 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 251092 T78 oasc.Overseer.close Overseer (id=92335883997216771-127.0.0.1:49216_solr-n_0000000000) closing
[junit4] 2> 251093 T114 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49216_solr
[junit4] 2> 251100 T119 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 251134 T78 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 251137 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 251138 T120 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 251241 T78 oasc.ZkTestServer.run start zk server on port:49221
[junit4] 2> 251254 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 251279 T126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4abfeb6 name:ZooKeeperConnection Watcher:127.0.0.1:49221 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 251280 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 251299 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 251299 T121 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1480aff50e50000, 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> 251308 T128 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a0f18be name:ZooKeeperConnection Watcher:127.0.0.1:49221 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 251308 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 251309 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 251325 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 251329 T130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@509bb0b6 name:ZooKeeperConnection Watcher:127.0.0.1:49221/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 251330 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 251330 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 251364 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 251367 T132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e229c50 name:ZooKeeperConnection Watcher:127.0.0.1:49221/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 251372 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 251372 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 251388 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 251398 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 251413 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 251421 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49221_solr
[junit4] 2> 251421 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 251435 T78 oasc.Overseer.start Overseer (id=92335884051218435-127.0.0.1:49221_solr-n_0000000000) starting
[junit4] 2> 251443 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 251471 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 251485 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 251494 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 251503 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 251512 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 251557 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 251568 T134 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 251572 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 251575 T133 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 251614 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 251643 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 251656 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 251661 T137 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70a676d6 name:ZooKeeperConnection Watcher:127.0.0.1:49221/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 251661 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 251666 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 251675 T78 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 251697 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 251704 T133 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> 251705 T133 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 251705 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 251726 T138 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> 251727 T139 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> 252202 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 252237 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 252262 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 252307 T133 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> 252308 T133 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 252308 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 252320 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 252323 T138 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> 252324 T139 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> 252778 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 252803 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 252818 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 252842 T133 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> 252842 T133 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 252842 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 252850 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 252853 T138 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> 252854 T139 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> 253328 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 253363 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 253386 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 253509 T138 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> 253510 T139 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> 253548 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 253557 T133 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> 253576 T133 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> 253586 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 253590 T133 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> 253590 T133 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 253590 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 253706 T138 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> 253706 T139 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> 254064 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 254097 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 254120 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254150 T133 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> 254151 T133 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 254151 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 254162 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254268 T139 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> 254269 T138 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> 254634 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 254653 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 254667 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254683 T133 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> 254684 T133 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 254684 T133 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 254691 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254694 T139 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> 254694 T138 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> 255174 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 255196 T78 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 255210 T140 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 255328 T139 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> 255329 T138 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> 256872 T139 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 256879 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49221 49221
[junit4] 2> 256914 T120 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49221 49221
[junit4] 2> 257157 T78 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 257157 T78 oasc.Overseer.close Overseer (id=92335884051218435-127.0.0.1:49221_solr-n_0000000000) closing
[junit4] 2> 257159 T133 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49221_solr
[junit4] 2> 257163 T141 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 257190 T78 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 257194 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 257196 T142 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 257296 T78 oasc.ZkTestServer.run start zk server on port:49227
[junit4] 2> 257298 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 257306 T148 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3da4cbe name:ZooKeeperConnection Watcher:127.0.0.1:49227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 257306 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 257504 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 257529 T150 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ca7a73f name:ZooKeeperConnection Watcher:127.0.0.1:49227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 257529 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 257530 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 257567 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 257580 T152 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49bbc7c7 name:ZooKeeperConnection Watcher:127.0.0.1:49227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 257581 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 257583 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 257633 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 257641 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 257649 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 257661 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 257666 T154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18d5ddf2 name:ZooKeeperConnection Watcher:127.0.0.1:49227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 257668 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 257673 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 257687 T78 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 257700 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 257706 T158 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19ca1f88 name:ZooKeeperConnection Watcher:127.0.0.1:49227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 257706 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 257707 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 257718 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 257730 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 257740 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 257744 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49227_solr
[junit4] 2> 257745 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 257753 T78 oasc.Overseer.start Overseer (id=92335884448169988-127.0.0.1:49227_solr-n_0000000000) starting
[junit4] 2> 257759 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 257769 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 257781 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 257791 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 257801 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 257814 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 257833 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 257834 T160 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 257838 T159 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 258842 T162 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 258847 T159 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> 258848 T159 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 258848 T159 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 258859 T156 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> 258859 T155 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> 259342 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 259367 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 259386 T162 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 259395 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 259425 T159 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 259426 T159 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 259449 T162 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 259455 T155 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> 259458 T156 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> 259845 T160 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:513)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:271)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 259846 T160 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92335884448169988-127.0.0.1:49227_solr-n_0000000000) am no longer a leader.
[junit4] 2> 260524 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 260540 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 260544 T164 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6449fcc1 name:ZooKeeperConnection Watcher:127.0.0.1:49227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 260544 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 260544 T78 oasc.Overseer.close Overseer (id=92335884448169988-127.0.0.1:49227_solr-n_0000000000) closing
[junit4] 2> 260546 T159 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49227_solr
[junit4] 2> 260546 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 260548 T165 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 260558 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 260563 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49227_solr
[junit4] 2> 260564 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 260572 T78 oasc.Overseer.start Overseer (id=92335884448169989-127.0.0.1:49227_solr-n_0000000001) starting
[junit4] 2> 260598 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 260599 T167 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 260603 T166 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 260612 T166 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> 260612 T166 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 260619 T169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 260620 T156 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> 260621 T155 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> 260637 T169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 260637 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 260659 T155 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 260672 T78 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/92335884448169987-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:148)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] 2> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] 2> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] 2> at java.lang.reflect.Method.invoke(Method.java:483)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 260677 T170 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 260711 T166 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 260718 T169 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 260721 T156 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> 262191 T170 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:150)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:163)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:125)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:210)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leaders/shard1
[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:240)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:237)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:237)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:487)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:417)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:404)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:142)
[junit4] 2> at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:137)
[junit4] 2> ... 10 more
[junit4] 2>
[junit4] 2> 262202 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49227 49227
[junit4] 2> 262213 T142 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49227 49227
[junit4] 2> 262490 T78 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 262490 T78 oasc.Overseer.close Overseer (id=92335884448169989-127.0.0.1:49227_solr-n_0000000001) closing
[junit4] 2> 262493 T166 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49227_solr
[junit4] 2> 262521 T171 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=A601EA9ABB719A1A -Dtests.slow=true -Dtests.locale=es_CU -Dtests.timezone=Etc/GMT+9 -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 5.42s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
[junit4] > at __randomizedtesting.SeedInfo.seed([A601EA9ABB719A1A:A2096569A9D4753B]:0)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:291)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:288)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:288)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:155)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:314)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:221)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:157)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:662)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 262592 T78 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 262595 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 262596 T172 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 262698 T78 oasc.ZkTestServer.run start zk server on port:49234
[junit4] 2> 262700 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262706 T178 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b0d0f22 name:ZooKeeperConnection Watcher:127.0.0.1:49234/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262707 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262708 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262712 T180 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@110411f4 name:ZooKeeperConnection Watcher:127.0.0.1:49234 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262712 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262723 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262734 T182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a2b3a5d name:ZooKeeperConnection Watcher:127.0.0.1:49234 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262738 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262738 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 262746 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 262754 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 262759 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 262762 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 262770 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 262777 T184 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53066dce name:ZooKeeperConnection Watcher:127.0.0.1:49234/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 262777 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 262777 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 262782 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 262787 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 262793 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 262797 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49234_solr
[junit4] 2> 262797 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 262801 T78 oasc.Overseer.start Overseer (id=92335884801998851-127.0.0.1:49234_solr-n_0000000000) starting
[junit4] 2> 262805 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 262811 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 262819 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 262827 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 262836 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 262845 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 262857 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 262859 T186 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 262866 T185 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 262883 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 262883 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 262890 T188 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 262892 T189 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> 262931 T188 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 262937 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 262937 T185 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 262937 T185 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 263049 T189 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> 263095 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49234 49234
[junit4] 2> 263130 T172 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49234 49234
[junit4] 2> 263367 T78 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 263368 T78 oasc.Overseer.close Overseer (id=92335884801998851-127.0.0.1:49234_solr-n_0000000000) closing
[junit4] 2> 263383 T185 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49234_solr
[junit4] 2> 263393 T190 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 263397 T78 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 263398 T78 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 263399 T191 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 263500 T78 oasc.ZkTestServer.run start zk server on port:49239
[junit4] 2> 263501 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 263509 T197 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@320974ed name:ZooKeeperConnection Watcher:127.0.0.1:49239/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 263510 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 263512 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 263517 T199 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a4423ab name:ZooKeeperConnection Watcher:127.0.0.1:49239 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 263517 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 263523 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 263528 T201 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5201af17 name:ZooKeeperConnection Watcher:127.0.0.1:49239 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 263528 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 263529 T78 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 263536 T78 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 263543 T78 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 263550 T78 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 263554 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 263562 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 263568 T203 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@80104d2 name:ZooKeeperConnection Watcher:127.0.0.1:49239/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 263568 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 263574 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 263588 T78 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 263600 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 263604 T207 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71d6b723 name:ZooKeeperConnection Watcher:127.0.0.1:49239/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 263604 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 263604 T78 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: retry=false
[junit4] 2> 263616 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 263621 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 263627 T78 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 263655 T78 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49239_solr
[junit4] 2> 263656 T78 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 263667 T78 oasc.Overseer.start Overseer (id=92335884854624260-127.0.0.1:49239_solr-n_0000000000) starting
[junit4] 2> 263671 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 263680 T78 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 263688 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 263697 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 263708 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 263716 T78 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 263729 T78 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 263733 T209 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 263740 T208 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 263756 T208 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> 263757 T208 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 263757 T208 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 263766 T211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 263767 T205 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> 263769 T204 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> 264238 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 264261 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 264274 T211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 264286 T78 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 264292 T213 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35154d6b name:ZooKeeperConnection Watcher:127.0.0.1:49239/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 264292 T78 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 264297 T78 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 264303 T78 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 264314 T211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 264314 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 264318 T208 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> 264318 T208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 264330 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 264343 T211 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 264456 T205 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> 264457 T214 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> 265773 T209 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:513)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:271)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 265773 T209 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=92335884854624260-127.0.0.1:49239_solr-n_0000000000) am no longer a leader.
[junit4] 2> 265961 T208 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-0000000001
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:190)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:187)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[juni
[...truncated too long message...]
ccurred - updating... (live nodes size: 1)
[junit4] 2> 374759 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 374797 T668 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 374803 T661 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 374803 T661 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 374803 T661 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 374918 T666 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> 374918 T667 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> 375298 T78 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 375332 T667 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:291)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:288)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:288)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:210)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 375333 T669 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:291)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:288)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:288)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:358)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3$1.run(SolrZkClient.java:210)
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2>
[junit4] 2> 375334 T665 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@618de4a6 rejected from java.util.concurrent.ThreadPoolExecutor@248f76f3[Shutting down, pool size = 1, active threads = 1, queued tasks = 0, completed tasks = 9]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2047)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:823)
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1369)
[junit4] 2> at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:112)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:207)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 375343 T78 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49342 49342
[junit4] 2> 375352 T648 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49342 49342
[junit4] 2> 375577 T78 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 375578 T78 oasc.Overseer.close Overseer (id=92335891954925571-127.0.0.1:49342_solr-n_0000000000) closing
[junit4] 2> 375580 T661 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:49342_solr
[junit4] 2> 375583 T670 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:308)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$8.execute(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:74)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:305)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:321)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:89)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:293)
[junit4] 2>
[junit4] 2> 378587 T78 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerTest-A601EA9ABB719A1A-001
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_CU, timezone=Etc/GMT+9
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_20 (64-bit)/cpus=2,threads=1,free=88432272,total=195035136
[junit4] 2> NOTE: All tests run in this JVM: [RangeFacetTest, RankQueryTest, TestJmxMonitoredMap, CachingDirectoryFactoryTest, TestStressRecovery, OverseerTest]
[junit4] Completed in 133.55s, 9 tests, 1 error <<< FAILURES!
[...truncated 1330 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:485: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:465: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:48: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:494: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1342: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:957: There were test failures: 430 suites, 1784 tests, 1 error, 47 ignored (20 assumptions)
Total time: 153 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any