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/04/03 20:36:36 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_60-ea-b10) -
Build # 3921 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3921/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([C80855F898E0DF05:CC00DA0B8A453024]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 45 more
Build Log:
[...truncated 11069 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-OverseerTest-1396548751275
[junit4] 2> 2364112 T7588 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 2364112 T7588 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2364112 T7588 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2364115 T7588 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2364116 T7588 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2364117 T7589 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2364190 T7588 oasc.ZkTestServer.run start zk server on port:59857
[junit4] 2> 2364191 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364195 T7595 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5254fae6 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364195 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364197 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364199 T7597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9c79016 name:ZooKeeperConnection Watcher:127.0.0.1:59857 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364199 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364202 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb50001, 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:744)
[junit4] 2>
[junit4] 2> 2364204 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364205 T7599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62356908 name:ZooKeeperConnection Watcher:127.0.0.1:59857 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364206 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364206 T7588 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2364209 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2364214 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364215 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364216 T7602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56c5c21d name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364216 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364216 T7604 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@514b2a6c name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364217 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364217 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2364217 T7588 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2364220 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2364220 T7588 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2364223 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2364226 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2364226 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2364226 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2364230 T7604 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2364231 T7600 oasc.Overseer.start Overseer (id=91524218964213763-127.0.0.1:59857_solr-n_0000000000) starting
[junit4] 2> 2364231 T7588 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2364235 T7600 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2364240 T7600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2364243 T7600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2364247 T7600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2364251 T7600 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2364258 T7600 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2364258 T7606 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2364260 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364262 T7608 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b9c907e name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364262 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364262 T7606 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91524218964213763-127.0.0.1:59857_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2364263 T7606 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2364263 T7606 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:294)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:207)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2364267 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2364267 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2364271 T7600 oasc.Overseer.start Overseer (id=91524218964213765-127.0.0.1:59857_solr-n_0000000001) starting
[junit4] 2> 2364285 T7610 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2364285 T7610 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2364286 T7609 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2364288 T7609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2364289 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2364289 T7609 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2364289 T7609 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2364292 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364293 T7604 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> 2364591 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2364603 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2364611 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364615 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364616 T7609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2364616 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2364622 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2364623 T7609 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2364629 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364630 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2364632 T7612 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5470548e name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2364632 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2364633 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2364636 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2364640 T7604 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2364641 T7612 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2364643 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364643 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2364645 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2364645 T7609 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2364650 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364653 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2364724 T7612 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2364724 T7604 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2364796 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2364800 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364800 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364800 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364802 T7609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2364803 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2364803 T7609 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2364803 T7609 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2364808 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2364881 T7612 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2364882 T7604 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365155 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365165 T7612 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365166 T7604 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365169 T7604 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2365169 T7604 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2365169 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365170 T7612 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2365179 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365179 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365180 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365182 T7609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365186 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365261 T7612 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> 2365313 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365315 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365317 T7614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b0d4e96 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365317 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365318 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2365321 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2365324 T7612 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365324 T7614 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365326 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365326 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365326 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365327 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365329 T7609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365329 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365329 T7609 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365334 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365335 T7614 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365335 T7612 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365340 T7614 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2365341 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365341 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365342 T7609 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365343 T7609 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365347 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365349 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365352 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365354 T7616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@66f08ab4 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365355 T7608 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365355 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365356 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2365358 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2365359 T7600 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2365361 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365363 T7614 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365363 T7616 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365363 T7618 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b082ed4 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365364 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365365 T7609 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59857_solr
[junit4] 2> 2365366 T7619 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2365368 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365369 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2365370 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2365372 T7600 oasc.Overseer.start Overseer (id=91524218964213769-127.0.0.1:59857_solr-n_0000000002) starting
[junit4] 2> 2365378 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365388 T7621 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2365388 T7621 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2365390 T7620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365390 T7620 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2365391 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365391 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365392 T7616 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365392 T7614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365396 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365397 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365397 T7616 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365397 T7614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365402 T7616 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365402 T7614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365405 T7620 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2365407 T7620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365408 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365408 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365410 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365411 T7614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365411 T7616 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365521 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365526 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365526 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365528 T7620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365528 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2365528 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365532 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365534 T7614 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365535 T7616 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365535 T7614 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2365535 T7614 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2365536 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365537 T7616 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2365544 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365548 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365624 T7616 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> 2365680 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365683 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365685 T7623 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d662bf4 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365685 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365686 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2365690 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2365693 T7623 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365693 T7616 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365696 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365696 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365697 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365697 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365698 T7620 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365699 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365699 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365704 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365707 T7623 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365707 T7616 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365710 T7623 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2365711 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365711 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365714 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365714 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365719 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365725 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365726 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365728 T7625 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79f977f6 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365729 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365730 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2365733 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2365736 T7623 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365736 T7625 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2365739 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365740 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365741 T7620 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365741 T7620 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365745 T7600 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2365745 T7618 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365748 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2365750 T7627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fdae0f1 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2365750 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2365752 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365752 T7620 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59857_solr
[junit4] 2> 2365753 T7628 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2365757 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2365757 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2365760 T7600 oasc.Overseer.start Overseer (id=91524218964213772-127.0.0.1:59857_solr-n_0000000003) starting
[junit4] 2> 2365779 T7630 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2365780 T7630 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2365781 T7629 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365781 T7629 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2365784 T7629 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365784 T7629 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365786 T7625 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365786 T7623 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365791 T7629 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365791 T7629 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365793 T7625 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365793 T7623 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365796 T7625 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365796 T7623 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365800 T7629 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2365800 T7629 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365800 T7623 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365801 T7625 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365803 T7629 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2365896 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365899 T7627 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365899 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2365901 T7629 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365901 T7629 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2365901 T7629 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2365904 T7627 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365906 T7625 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365906 T7623 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2365910 T7625 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365910 T7623 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2365911 T7625 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2365912 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365917 T7627 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365918 T7629 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2365921 T7627 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2365995 T7625 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> 2366054 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366056 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366058 T7632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61bfbbf5 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366059 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366060 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2366063 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2366065 T7600 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2366067 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb5000c, 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:744)
[junit4] 2>
[junit4] 2> 2366067 T7632 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366067 T7625 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366068 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366069 T7634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c289114 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366070 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366071 T7629 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59857_solr
[junit4] 2> 2366072 T7635 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2366073 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366076 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2366076 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2366079 T7600 oasc.Overseer.start Overseer (id=91524218964213774-127.0.0.1:59857_solr-n_0000000004) starting
[junit4] 2> 2366084 T7632 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366086 T7632 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2366088 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366098 T7637 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2366098 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366099 T7636 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2366099 T7637 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2366101 T7639 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bcdcce8 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366101 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366103 T7636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366103 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2366103 T7636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366103 T7636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366105 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2366107 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366108 T7639 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> 2366109 T7632 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> 2366122 T7632 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366123 T7639 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366125 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366126 T7636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366127 T7636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366127 T7636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366130 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366134 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366135 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366137 T7636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366137 T7636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366139 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366216 T7639 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366216 T7632 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366277 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366279 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366280 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366280 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366279 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366283 T7636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366284 T7636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2366284 T7636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366288 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366292 T7632 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366292 T7639 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366293 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366293 T7639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2366299 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366303 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366376 T7639 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> 2366436 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366438 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366440 T7641 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e01e541 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366440 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366441 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2366443 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2366446 T7639 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366446 T7641 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366449 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366449 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366449 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366449 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366451 T7636 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366451 T7636 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366451 T7636 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366455 T7634 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366456 T7600 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2366457 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb5000e, 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:744)
[junit4] 2>
[junit4] 2> 2366458 T7641 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366459 T7600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366459 T7639 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366461 T7643 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b7700a2 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366461 T7600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366463 T7636 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:59857_solr
[junit4] 2> 2366463 T7641 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2366464 T7644 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2366466 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366467 T7600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59857_solr
[junit4] 2> 2366467 T7600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2366471 T7600 oasc.Overseer.start Overseer (id=91524218964213777-127.0.0.1:59857_solr-n_0000000005) starting
[junit4] 2> 2366476 T7588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2366479 T7646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a3c6d89 name:ZooKeeperConnection Watcher:127.0.0.1:59857/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2366479 T7588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2366480 T7588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2366483 T7588 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2366488 T7641 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366488 T7646 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2366488 T7648 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2366489 T7648 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:59857_solr
[junit4] 2> 2366490 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366490 T7647 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366491 T7647 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2366492 T7647 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366492 T7647 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366492 T7641 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366492 T7646 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366495 T7647 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2366497 T7647 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366498 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366499 T7647 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366499 T7647 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366501 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366502 T7646 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366502 T7641 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366506 T7647 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366509 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366510 T7647 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2366510 T7647 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366513 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366587 T7641 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366587 T7646 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2366641 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366644 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366645 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366645 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366644 T7588 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2366646 T7647 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366647 T7647 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2366648 T7647 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2366652 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366656 T7646 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2366658 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb50010, 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:744)
[junit4] 2>
[junit4] 2> 2366659 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366659 T7646 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2366667 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366671 T7643 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2366745 T7646 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> 2366802 T7588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2366845 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb50011, 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:744)
[junit4] 2>
[junit4] 2> 2366848 T7646 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2366850 T7590 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cacfb50000, 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:744)
[junit4] 2>
[junit4] 2> 2366851 T7588 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59857 59857
[junit4] 2> 2366976 T7623 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2368466 T7623 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2367721 T7641 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2368468 T7641 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2368469 T7641 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[...truncated too long message...]
ed
[junit4] 2> 2418155 T8062 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2418161 T8063 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2418172 T8062 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2418307 T8066 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> 2418307 T8060 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> 2418355 T8066 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2418358 T8051 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14528cb91110004, 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:744)
[junit4] 2>
[junit4] 2> 2418365 T7588 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60313 60313
[junit4] 2> 2421200 T8050 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:60313 60313
[junit4] 2> 2421202 T7588 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 2421202 T8063 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:60313_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2421205 T8067 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2421205 T7588 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2421206 T7588 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2424981 T7588 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=71), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=71)), sim=DefaultSimilarity, locale=ar_SA, timezone=America/Indiana/Indianapolis
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=307356144,total=535822336
[junit4] 2> NOTE: All tests run in this JVM: [TestUniqueKeyFieldResource, FileUtilsTest, TestExceedMaxTermLength, DistributedSpellCheckComponentTest, TestConfig, TestPseudoReturnFields, StatsComponentTest, CollectionsAPIDistributedZkTest, ZkCLITest, InfoHandlerTest, NotRequiredUniqueKeyTest, RemoteQueryErrorTest, TestCopyFieldCollectionResource, BasicFunctionalityTest, SolrCoreCheckLockOnStartupTest, TestUtils, TestSchemaResource, DistributedQueryElevationComponentTest, TestJmxMonitoredMap, PluginInfoTest, TestCloudManagedSchemaAddField, TestWordDelimiterFilterFactory, IndexSchemaTest, TestComplexPhraseQParserPlugin, TestSurroundQueryParser, TestSolrXmlPersistence, TestRecoveryHdfs, TestFastLRUCache, ExpressionTest, AnalysisAfterCoreReloadTest, MoreLikeThisHandlerTest, SuggesterTest, HighlighterTest, TestSolrJ, DistribDocExpirationUpdateProcessorTest, SolrIndexSplitterTest, SpellingQueryConverterTest, FileBasedSpellCheckerTest, TestDynamicFieldCollectionResource, TestFastOutputStream, TestImplicitCoreProperties, TestMultiCoreConfBootstrap, TestRandomFaceting, ConvertedLegacyTest, TestFastWriter, TestSolrXml, SSLMigrationTest, ClusterStateTest, SchemaVersionSpecificBehaviorTest, SortByFunctionTest, SimplePostToolTest, TestFreeTextSuggestions, TestRandomMergePolicy, TestCoreContainer, DateFieldTest, HdfsWriteToMultipleCollectionsTest, TestCSVLoader, TestPostingsSolrHighlighter, TestRestManager, DocValuesMultiTest, TestJoin, CoreAdminRequestStatusTest, TestAnalyzedSuggestions, DistributedTermsComponentTest, SolrCoreTest, TestSolrCoreProperties, TestQueryTypes, TestSolr4Spatial, TestStressReorder, TestQuerySenderListener, CopyFieldTest, TestFuzzyAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, TestCollectionAPI, AsyncMigrateRouteKeyTest, MBeansHandlerTest, UpdateParamsTest, DirectSolrSpellCheckerTest, TestNonNRTOpen, TestSolrDeletionPolicy1, TestCoreDiscovery, HdfsRecoveryZkTest, DefaultValueUpdateProcessorTest, HdfsLockFactoryTest, HardAutoCommitTest, CustomCollectionTest, RangeFacetTest, MinimalSchemaTest, ClusterStateUpdateTest, SearchHandlerTest, MultiTermTest, HighlighterConfigTest, DeleteInactiveReplicaTest, NoCacheHeaderTest, TestFieldTypeResource, TestInitQParser, TestTrie, SolrIndexConfigTest, TestPHPSerializedResponseWriter, TestRandomDVFaceting, TestPhraseSuggestions, TermsComponentTest, TestJmxIntegration, TestDistributedGrouping, SpellPossibilityIteratorTest, RegexBoostProcessorTest, TestReloadAndDeleteDocs, OverseerRolesTest, CursorPagingTest, TestCodecSupport, TestFunctionQuery, TestLuceneMatchVersion, TestDistribDocBasedVersion, TestManagedResourceStorage, JsonLoaderTest, AnalysisErrorHandlingTest, CursorMarkTest, SolrCmdDistributorTest, TestSerializedLuceneMatchVersion, HdfsDirectoryTest, ChangedSchemaMergeTest, FieldMutatingUpdateProcessorTest, SignatureUpdateProcessorFactoryTest, TestClassNameShortening, TriLevelCompositeIdRoutingTest, TestShortCircuitedRequests, TestStressVersions, RAMDirectoryFactoryTest, TestIndexSearcher, DocValuesTest, RecoveryZkTest, TestStressUserVersions, BasicZkTest, TestPartialUpdateDeduplication, SliceStateTest, CircularListTest, TestLRUCache, TestSearcherReuse, TestSchemaNameResource, QueryParsingTest, StressHdfsTest, OpenExchangeRatesOrgProviderTest, TestNonDefinedSimilarityFactory, HdfsUnloadDistributedZkTest, TestLMJelinekMercerSimilarityFactory, AutoCommitTest, BlockCacheTest, TestSolrQueryParser, TermVectorComponentDistributedTest, ShowFileRequestHandlerTest, TestSimpleQParserPlugin, DirectUpdateHandlerTest, TestExtendedDismaxParser, TestXIncludeConfig, SolrXmlInZkTest, FieldFacetExtrasTest, TestMergePolicyConfig, TestSolrXMLSerializer, LoggingHandlerTest, CSVRequestHandlerTest, XsltUpdateRequestHandlerTest, TestDistributedMissingSort, TestFiltering, AliasIntegrationTest, UpdateRequestProcessorFactoryTest, TestStressRecovery, TestShardHandlerFactory, QueryResultKeyTest, QueryEqualityTest, TestHighlightDedupGrouping, TestRemoteStreaming, TestManagedResource, TestBinaryResponseWriter, TestSolrQueryParserDefaultOperatorResource, TestExpandComponent, TestCustomSort, TestInfoStreamLogging, DateMathParserTest, TestZkChroot, MigrateRouteKeyTest, TestReversedWildcardFilterFactory, CoreContainerCoreInitFailuresTest, TestWriterPerf, DistributedSuggestComponentTest, TestAnalyzeInfixSuggestions, TestSort, CoreMergeIndexesAdminHandlerTest, LeaderElectionTest, TestMaxScoreQueryParser, FieldFacetTest, HdfsSyncSliceTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest]
[junit4] Completed in 60.92s, 9 tests, 1 error <<< FAILURES!
[...truncated 589 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1275: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 error, 42 ignored (21 assumptions)
Total time: 93 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b10 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.8.0) - Build # 3922
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3922/
Java: 32bit/jdk1.8.0 -server -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([1EFC428A883A1EB5:1AF4CD799A9FF194]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
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:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 46 more
Build Log:
[...truncated 10997 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-OverseerTest-1396577171103
[junit4] 2> 2148471 T7341 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 2148471 T7341 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2148471 T7341 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2148475 T7341 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 2148475 T7341 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2148476 T7342 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2148577 T7341 oasc.ZkTestServer.run start zk server on port:54883
[junit4] 2> 2148580 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148586 T7348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf8238 name:ZooKeeperConnection Watcher:127.0.0.1:54883 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148587 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148594 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148596 T7350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ed2f06 name:ZooKeeperConnection Watcher:127.0.0.1:54883 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148597 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148597 T7341 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2148603 T7343 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7c76ad0001, 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:744)
[junit4] 2>
[junit4] 2> 2148605 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148607 T7352 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17eb068 name:ZooKeeperConnection Watcher:127.0.0.1:54883/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148608 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148608 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2148612 T7341 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2148616 T7341 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2148619 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2148625 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148627 T7354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@120b44d name:ZooKeeperConnection Watcher:127.0.0.1:54883/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148627 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148629 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2148633 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2148639 T7352 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2148639 T7354 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2148640 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2148642 T7356 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74d93 name:ZooKeeperConnection Watcher:127.0.0.1:54883/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2148642 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2148643 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2148648 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2148655 T7341 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54883_solr
[junit4] 2> 2148655 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2148660 T7341 oasc.Overseer.start Overseer (id=91526081486323716-127.0.0.1:54883_solr-n_0000000000) starting
[junit4] 2> 2148664 T7341 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2148669 T7341 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2148674 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2148679 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2148684 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2148688 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2148698 T7358 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2148699 T7358 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54883_solr
[junit4] 2> 2148699 T7357 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2149703 T7356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2149706 T7357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2149707 T7357 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> 2149707 T7357 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2149715 T7357 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2149719 T7356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2149721 T7352 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> 2149721 T7354 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> 2150203 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2150217 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2150226 T7356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2150226 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2150227 T7357 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2150231 T7356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2150231 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2150233 T7357 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> 2150233 T7357 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2150237 T7356 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2150341 T7352 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> 2150341 T7354 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> 2151398 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2151416 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2151420 T7360 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a6c30a name:ZooKeeperConnection Watcher:127.0.0.1:54883/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2151420 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2151422 T7357 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54883_solr
[junit4] 2> 2151425 T7361 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2151431 T7341 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54883_solr
[junit4] 2> 2151432 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2151437 T7341 oasc.Overseer.start Overseer (id=91526081486323717-127.0.0.1:54883_solr-n_0000000001) starting
[junit4] 2> 2151462 T7363 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2151464 T7363 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54883_solr
[junit4] 2> 2151464 T7362 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2151468 T7362 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2151469 T7362 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> 2151469 T7362 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2151474 T7360 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151476 T7352 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> 2151476 T7354 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> 2151531 T7360 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151532 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2151533 T7362 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2151544 T7341 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91526081486323715-node1_core1-n_0000000002
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[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:1617)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2151548 T7354 oasc.LeaderElector.checkIfIamLeader WARN Our node is no longer in line to be leader
[junit4] 2> 2151550 T7341 oasc.LeaderElector.checkIfIamLeader WARN Failed setting watch org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election/91526081486323715-node1_core1-n_0000000000
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:127)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] 2> at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
[junit4] 2> at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[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:1617)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4] 2> at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
[junit4] 2> at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4] 2> at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4] 2> at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4] 2> at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4] 2> at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4] 2> at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4] 2> at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2151552 T7362 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1069)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:241)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2151555 T7354 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2151557 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2151559 T7360 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151572 T7360 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151575 T7362 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2151583 T7360 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2151686 T7352 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> 2151687 T7354 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> 2152564 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2153570 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2154576 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2155584 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2156672 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2157777 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2158887 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2159996 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2161103 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2162208 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2163314 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2164421 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2165527 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2166636 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2167645 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2167652 T7352 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2167653 T7354 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2167654 T7343 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7c76ad0003, 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:744)
[junit4] 2>
[junit4] 2> 2167656 T7343 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7c76ad0005, 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:744)
[junit4] 2>
[junit4] 2> 2167658 T7343 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7c76ad0002, 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:744)
[junit4] 2>
[junit4] 2> 2167661 T7341 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54883 54883
[junit4] 2> 2169894 T7342 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54883 54883
[junit4] 2> 2169896 T7341 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 2169897 T7362 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54883_solr
[junit4] 2> 2169900 T7364 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=1EFC428A883A1EB5 -Dtests.slow=true -Dtests.locale=de_AT -Dtests.timezone=America/Argentina/Buenos_Aires -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 21.4s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([1EFC428A883A1EB5:1AF4CD799A9FF194]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] > ... 46 more
[junit4] 2> 2169917 T7341 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 2169918 T7341 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2169919 T7365 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2170019 T7341 oasc.ZkTestServer.run start zk server on port:54904
[junit4] 2> 2170021 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2170029 T7371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12f39e0 name:ZooKeeperConnection Watcher:127.0.0.1:54904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2170029 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2170031 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2170052 T7373 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ad6d9e name:ZooKeeperConnection Watcher:127.0.0.1:54904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2170052 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2170090 T7366 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7cca700001, 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:744)
[junit4] 2>
[junit4] 2> 2170092 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2170094 T7375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fd7206 name:ZooKeeperConnection Watcher:127.0.0.1:54904 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2170094 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2170094 T7341 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2170099 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2170102 T7341 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2170106 T7341 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2170108 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2170113 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2170115 T7377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bdf714 name:ZooKeeperConnection Watcher:127.0.0.1:54904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2170116 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2170117 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2170121 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2170125 T7377 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2170126 T7371 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2170127 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2170129 T7379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1612d7a name:ZooKeeperConnection Watcher:127.0.0.1:54904/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2170130 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2170131 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2170134 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2170139 T7341 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54904_solr
[junit4] 2> 2170140 T7341 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2170143 T7341 oasc.Overseer.start Overseer (id=91526082891612164-127.0.0.1:54904_solr-n_0000000000) starting
[junit4] 2> 2170147 T7341 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2170151 T7341 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2170156 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2170162 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2170167 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2170173 T7341 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2170187 T7381 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2170189 T7381 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54904_solr
[junit4] 2> 2170192 T7380 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2170196 T7380 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2170196 T7380 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> 2170197 T7380 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 2170197 T7380 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2170203 T7379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2170205 T7377 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> 2170205 T7371 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> 2170686 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2170706 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2170716 T7379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2170717 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2170719 T7380 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2170720 T7366 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7cca700004, 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:744)
[junit4] 2>
[junit4] 2> 2170721 T7377 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2170722 T7371 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2170723 T7366 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7cca700003, 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:744)
[junit4] 2>
[junit4] 2> 2170726 T7366 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7cca700000, 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:744)
[junit4] 2>
[junit4] 2> 2170726 T7341 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54904 54904
[junit4] 2> 2172204 T7380 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /clusterstate.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ClusterState.load(ClusterState.java:239)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:422)
[junit4] 2> at org.apache.solr.common.cloud.ZkStateReader.updateClusterState(ZkStateReader.java:240)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:233)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2172958 T7380 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54904_solr
[junit4] 2> 2172959 T7365 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54904 54904
[junit4] 2> 2172961 T7382 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2172962 T7341 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2172970 T7341 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2172970 T7341 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2172971 T7383 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2173071 T7341 oasc.ZkTestServer.run start zk server on port:54922
[junit4] 2> 2173073 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173079 T7389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1847555 name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173079 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173080 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173083 T7391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c75aa1 name:ZooKeeperConnection Watcher:127.0.0.1:54922 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173083 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173123 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173126 T7393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1300d9a name:ZooKeeperConnection Watcher:127.0.0.1:54922 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173126 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173126 T7341 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2173131 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2173131 T7384 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1452a7cd65e0002, 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:744)
[junit4] 2>
[junit4] 2> 2173138 T7394 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173139 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173142 T7396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@83d29d name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173143 T7394 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173143 T7398 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@112e13b name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173143 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173144 T7394 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2173144 T7341 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2173148 T7394 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2173148 T7341 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2173151 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2173155 T7394 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54922_solr
[junit4] 2> 2173155 T7394 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2173156 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2173158 T7394 oasc.Overseer.start Overseer (id=91526083091759107-127.0.0.1:54922_solr-n_0000000000) starting
[junit4] 2> 2173166 T7398 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2173166 T7394 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2173167 T7341 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2173172 T7394 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2173178 T7394 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2173182 T7394 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2173187 T7394 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2173194 T7394 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2173202 T7394 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2173203 T7400 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2173207 T7394 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173209 T7402 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@443cfd name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173209 T7394 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173210 T7400 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91526083091759107-127.0.0.1:54922_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2173210 T7400 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54922_solr
[junit4] 2> 2173210 T7400 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:294)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:207)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2173215 T7394 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54922_solr
[junit4] 2> 2173216 T7394 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2173219 T7394 oasc.Overseer.start Overseer (id=91526083091759109-127.0.0.1:54922_solr-n_0000000001) starting
[junit4] 2> 2173237 T7404 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2173238 T7404 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54922_solr
[junit4] 2> 2173238 T7403 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2173241 T7403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2173242 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2173242 T7403 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2173243 T7403 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2173246 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173248 T7398 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> 2173668 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2173687 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2173698 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173701 T7403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2173703 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2173703 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173710 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2173711 T7403 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2173717 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173720 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2173722 T7406 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11a0c91 name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2173723 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2173725 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2173729 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2173736 T7406 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2173736 T7398 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2173740 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2173740 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173744 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2173744 T7403 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2173753 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173754 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2173857 T7406 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2173858 T7398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2173955 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2173963 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173963 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173964 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2173966 T7403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2173967 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2173967 T7403 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 2173968 T7403 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2173973 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174076 T7406 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174076 T7398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174458 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2174475 T7406 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2174475 T7398 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2174476 T7398 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2174477 T7398 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2174478 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174479 T7406 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2174490 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174491 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174492 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174494 T7403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174500 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174603 T7406 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> 2174680 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174683 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2174686 T7408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@195681 name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2174686 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2174689 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2174694 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2174699 T7406 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2174700 T7408 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2174703 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2174703 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174704 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174704 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174708 T7403 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174709 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2174709 T7403 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2174716 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174716 T7406 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2174718 T7408 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2174721 T7408 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2174722 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174722 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2174724 T7403 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2174725 T7403 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2174732 T7394 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2174734 T7402 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174738 T7394 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2174740 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2174741 T7410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bb9ed name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2174741 T7394 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2174742 T7403 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:54922_solr
[junit4] 2> 2174745 T7413 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2174746 T7412 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ccf05 name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2174747 T7341 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2174752 T7341 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2174754 T7394 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54922_solr
[junit4] 2> 2174754 T7394 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2174759 T7341 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 2174760 T7394 oasc.Overseer.start Overseer (id=91526083091759112-127.0.0.1:54922_solr-n_0000000002) starting
[junit4] 2> 2174768 T7412 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2174770 T7408 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2174773 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2174788 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174790 T7415 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2174791 T7415 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:54922_solr
[junit4] 2> 2174796 T7414 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174797 T7414 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2174798 T7414 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2174798 T7414 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2174801 T7412 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174801 T7408 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174810 T7414 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2174810 T7414 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2174813 T7412 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174813 T7408 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174819 T7414 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2174823 T7414 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174829 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174832 T7412 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174832 T7408 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174842 T7414 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174844 T7414 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state1",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 2174844 T7414 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2174850 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174953 T7412 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174953 T7408 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2174989 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174995 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174995 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174995 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2174995 T7341 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2174998 T7414 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2174999 T7414 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"state2",
[junit4] 2> "node_name":"node2",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node2/solr/"}
[junit4] 2> 2174999 T7414 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2175004 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2175010 T7412 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2175012 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2175013 T7412 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2175022 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2175028 T7410 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2175130 T7412 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> 2175212 T7341 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2175218 T7341 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2175240 T7417 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@161fee4 name:ZooKeeperConnection Watcher:127.0.0.1:54922/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2175241 T7341 oascc.Co
[...truncated too long message...]
processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2204930 T7729 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2204933 T7341 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55249 55249
[junit4] 2> 2207481 T7713 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55249 55249
[junit4] 2> 2207487 T7341 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 2207489 T7726 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:55249_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2207519 T7730 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2207522 T7341 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2207522 T7341 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2211081 T7341 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=de_AT, timezone=America/Argentina/Buenos_Aires
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0 (32-bit)/cpus=2,threads=1,free=119718648,total=438304768
[junit4] 2> NOTE: All tests run in this JVM: [TestSearchPerf, TestCursorMarkWithoutUniqueKey, TestExtendedDismaxParser, StatsComponentTest, TestCSVResponseWriter, TestTrie, TestSolrQueryParserDefaultOperatorResource, TestSolrQueryParser, TestDistributedGrouping, BadIndexSchemaTest, TestManagedResource, TestJoin, QueryElevationComponentTest, SuggestComponentTest, QueryFacetTest, TestExceedMaxTermLength, HdfsLockFactoryTest, TestFieldCollectionResource, TestNonDefinedSimilarityFactory, NotRequiredUniqueKeyTest, DistribCursorPagingTest, ShardRoutingTest, AbstractAnalyticsStatsTest, OverseerCollectionProcessorTest, AddSchemaFieldsUpdateProcessorFactoryTest, FileUtilsTest, TestReversedWildcardFilterFactory, TestDefaultSearchFieldResource, TestWordDelimiterFilterFactory, DeleteInactiveReplicaTest, TestFreeTextSuggestions, TestCopyFieldCollectionResource, TestOmitPositions, TestPseudoReturnFields, TestRecovery, LukeRequestHandlerTest, SystemInfoHandlerTest, TestQueryUtils, TestShardHandlerFactory, MoreLikeThisHandlerTest, TestZkChroot, DateMathParserTest, DistributedTermsComponentTest, TestSolrJ, DirectUpdateHandlerTest, SimpleFacetsTest, TestRandomFaceting, TestInfoStreamLogging, TestFieldTypeCollectionResource, TestMaxScoreQueryParser, SpellCheckCollatorTest, FieldFacetExtrasTest, TestCSVLoader, ChangedSchemaMergeTest, UpdateParamsTest, TestNonNRTOpen, TestStressVersions, HdfsUnloadDistributedZkTest, BasicFunctionalityTest, TestCollationField, TestSchemaResource, TestSolrIndexConfig, LoggingHandlerTest, TestHashPartitioner, TestRemoteStreaming, DistributedExpandComponentTest, HdfsCollectionsAPIDistributedZkTest, BasicZkTest, DistributedQueryElevationComponentTest, TestRangeQuery, TestDynamicFieldCollectionResource, TestDocumentBuilder, ZkSolrClientTest, TestUniqueKeyFieldResource, QueryParsingTest, IndexSchemaRuntimeFieldTest, PeerSyncTest, TestPHPSerializedResponseWriter, DistributedDebugComponentTest, TestSchemaVersionResource, TestStressLucene, OverseerRolesTest, ResponseLogComponentTest, SOLR749Test, TestFiltering, TestManagedSchemaFieldResource, TestPerFieldSimilarity, BadComponentTest, TestSolrXml, TestModifyConfFiles, TestFileDictionaryLookup, FileBasedSpellCheckerTest, SSLMigrationTest, TestFoldingMultitermQuery, FunctionTest, ClusterStateTest, WordBreakSolrSpellCheckerTest, RegexBoostProcessorTest, TestArbitraryIndexDir, TestDynamicFieldResource, UniqFieldsUpdateProcessorFactoryTest, TestFieldTypeResource, TestPhraseSuggestions, TriLevelCompositeIdRoutingTest, SolrCoreCheckLockOnStartupTest, SpellPossibilityIteratorTest, ShardRoutingCustomTest, CoreAdminRequestStatusTest, TestConfigSets, SignatureUpdateProcessorFactoryTest, TestFieldResource, TestXIncludeConfig, TestSolrXmlPersistor, TestPostingsSolrHighlighter, TestSystemIdResolver, TestLFUCache, ReturnFieldsTest, DebugComponentTest, TestBM25SimilarityFactory, FullSolrCloudDistribCmdsTest, StressHdfsTest, TestFuzzyAnalyzedSuggestions, TestComplexPhraseQParserPlugin, TestDistribDocBasedVersion, HdfsSyncSliceTest, TestGroupingSearch, SolrIndexSplitterTest, TestStressRecovery, PolyFieldTest, TestConfig, TestFastLRUCache, OverseerStatusTest, AbstractAnalyticsFacetTest, FieldAnalysisRequestHandlerTest, BlockCacheTest, TestRecoveryHdfs, NoFacetTest, AsyncMigrateRouteKeyTest, DocumentAnalysisRequestHandlerTest, TestFaceting, SuggesterTSTTest, TermsComponentTest, StandardRequestHandlerTest, MinimalSchemaTest, ZkCLITest, PingRequestHandlerTest, SchemaVersionSpecificBehaviorTest, ScriptEngineTest, TestStressReorder, StatelessScriptUpdateProcessorFactoryTest, SpellCheckComponentTest, TestCoreDiscovery, TestAddFieldRealTimeGet, TestManagedStopFilterFactory, TestSearcherReuse, TestCollapseQParserPlugin, DeleteReplicaTest, TestReload, TestMergePolicyConfig, HdfsWriteToMultipleCollectionsTest, BinaryUpdateRequestHandlerTest, SolrPluginUtilsTest, TestCollationFieldDocValues, TestBinaryField, CacheHeaderTest, AnalysisErrorHandlingTest, SliceStateTest, SimplePostToolTest, TestLMJelinekMercerSimilarityFactory, TestAnalyzedSuggestions, HdfsDirectoryTest, ZkNodePropsTest, TestAtomicUpdateErrorCases, DistributedSpellCheckComponentTest, DisMaxRequestHandlerTest, TestWriterPerf, CollectionsAPIDistributedZkTest, SolrCoreTest, TestDefaultSimilarityFactory, ConvertedLegacyTest, MigrateRouteKeyTest, SoftAutoCommitTest, ExpressionTest, BJQParserTest, TestCollectionAPI, EchoParamsTest, UpdateRequestProcessorFactoryTest, TestManagedSchema, TestJmxMonitoredMap, TermVectorComponentTest, TestLazyCores, TestSerializedLuceneMatchVersion, BasicDistributedZk2Test, TestManagedSynonymFilterFactory, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest]
[junit4] Completed in 62.67s, 9 tests, 1 error <<< FAILURES!
[...truncated 592 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1275: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 error, 42 ignored (21 assumptions)
Total time: 88 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0 -server -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure