You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/04 09:39:17 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_60-ea-b14) - Build
# 10119 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10119/
Java: 32bit/jdk1.7.0_60-ea-b14 -client -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
Stack Trace:
org.apache.zookeeper.KeeperException$NoNodeException: KeeperErrorCode = NoNode for /collections/collection1/leader_elect/shard1/election
at __randomizedtesting.SeedInfo.seed([2D7D728CDE53BBDC:2975FD7FCCF654FD]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:111)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:134)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 11399 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-2D7D728CDE53BBDC-001/init-core-data-001
[junit4] 2> 926987 T4147 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 926988 T4147 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 926988 T4147 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 926991 T4147 oas.SolrTestCaseJ4.setUp ###Starting testBadQueueItem
[junit4] 2> 926991 T4147 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 926992 T4148 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 927092 T4147 oasc.ZkTestServer.run start zk server on port:35259
[junit4] 2> 927093 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929379 T4151 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 2285ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 929380 T4154 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1381869 name:ZooKeeperConnection Watcher:127.0.0.1:35259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929381 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929384 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929385 T4156 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10aff97 name:ZooKeeperConnection Watcher:127.0.0.1:35259 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929385 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929385 T4147 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 929390 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929392 T4158 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@de51 name:ZooKeeperConnection Watcher:127.0.0.1:35259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929393 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929393 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 929396 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929398 T4160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2952d9 name:ZooKeeperConnection Watcher:127.0.0.1:35259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929398 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929399 T4147 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 929401 T4147 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 929404 T4147 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:35259_solr
[junit4] 2> 929404 T4147 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 929405 T4147 oasc.Overseer.start Overseer (id=91697226658349059-127.0.0.1:35259_solr-n_0000000000) starting
[junit4] 2> 929406 T4147 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 929408 T4147 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 929410 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 929412 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 929413 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 929415 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 929420 T4162 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 929421 T4147 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 929421 T4161 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 929421 T4162 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:35259_solr
[junit4] 2> 929422 T4147 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 929424 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 929425 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929426 T4164 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3767bb name:ZooKeeperConnection Watcher:127.0.0.1:35259/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929427 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929427 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 929429 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 929431 T4158 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 929431 T4164 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 929432 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 929433 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 929434 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 929434 T4161 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 929434 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 929436 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 929438 T4164 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> 929438 T4158 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> 929933 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 929940 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 929943 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 929944 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 929944 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 929946 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 929946 T4161 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 929946 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 929948 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930050 T4158 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> 930050 T4164 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> 930444 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 930452 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 930455 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930455 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930455 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930456 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930456 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930458 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 930458 T4161 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 930459 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 930460 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930562 T4158 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> 930562 T4164 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> 930956 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 930962 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 930966 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930966 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930967 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 930967 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 930971 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931073 T4164 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> 931073 T4158 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> 931119 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931119 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931120 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931121 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931122 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 931122 T4161 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":"",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 931125 T4161 oasc.Overseer$ClusterStateUpdater.checkKeyExistence ERROR Skipping invalid Overseer message because it has no collection specified: {
[junit4] 2> "operation":"deletecore",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core0",
[junit4] 2> "core_node_name":"node0",
[junit4] 2> "collection":""}
[junit4] 2> 931126 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931127 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 931127 T4161 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection2 with shards [shard1, shard2, shard3]
[junit4] 2> 931127 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 931129 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931231 T4158 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> 931231 T4164 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> 931622 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard2/election
[junit4] 2> 931630 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard2
[junit4] 2> 931633 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931633 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931633 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931634 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931634 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 931636 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 931636 T4161 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 931636 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 931638 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 931740 T4158 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> 931740 T4164 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> 932134 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard1/election
[junit4] 2> 932140 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard1
[junit4] 2> 932143 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932144 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932144 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932145 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932145 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 932147 T4161 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection2",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 932148 T4161 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 932148 T4161 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 932149 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932251 T4164 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> 932251 T4158 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> 932645 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leader_elect/shard3/election
[junit4] 2> 932653 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection2/leaders/shard3
[junit4] 2> 932658 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932658 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932659 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932660 T4161 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 932664 T4160 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 932765 T4158 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> 932765 T4164 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> 932810 T4164 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 932811 T4147 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:35259 35259
[junit4] 2> 933025 T4148 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:35259 35259
[junit4] 2> 933026 T4147 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 933027 T4161 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:35259_solr
[junit4] 2> 933028 T4166 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> 933033 T4147 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 933034 T4147 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 933035 T4167 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 933135 T4147 oasc.ZkTestServer.run start zk server on port:57744
[junit4] 2> 933136 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933138 T4173 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cd363 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933138 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933139 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933140 T4175 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bbf7b name:ZooKeeperConnection Watcher:127.0.0.1:57744 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933140 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933142 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933142 T4177 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1efde24 name:ZooKeeperConnection Watcher:127.0.0.1:57744 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933143 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933143 T4147 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 933145 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 933147 T4178 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933148 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933148 T4181 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eb5268 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933149 T4182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16f64c9 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933149 T4178 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933149 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933150 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 933150 T4147 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 933151 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 933151 T4147 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 933153 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 933153 T4178 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57744_solr
[junit4] 2> 933153 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 933154 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 933155 T4178 oasc.Overseer.start Overseer (id=91697227054383107-127.0.0.1:57744_solr-n_0000000000) starting
[junit4] 2> 933156 T4182 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 933156 T4178 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 933156 T4147 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 933158 T4178 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 933162 T4178 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 933165 T4178 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 933167 T4178 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 933168 T4178 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 933172 T4184 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 933172 T4178 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 933172 T4184 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57744_solr
[junit4] 2> 933172 T4183 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 933173 T4183 oasc.Overseer$ClusterStateUpdater.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$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.amILeader(Overseer.java:578)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:206)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 933173 T4178 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933173 T4183 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=91697227054383107-127.0.0.1:57744_solr-n_0000000000) am no longer a leader.
[junit4] 2> 933174 T4183 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57744_solr
[junit4] 2> 933174 T4186 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a4541a name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933174 T4187 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> 933174 T4178 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933175 T4184 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:299)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:212)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 933177 T4178 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57744_solr
[junit4] 2> 933177 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 933178 T4178 oasc.Overseer.start Overseer (id=91697227054383109-127.0.0.1:57744_solr-n_0000000001) starting
[junit4] 2> 933185 T4189 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 933185 T4189 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57744_solr
[junit4] 2> 933186 T4188 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 933187 T4188 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 933187 T4188 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> 933187 T4188 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 933188 T4188 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 933192 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933193 T4182 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> 933660 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 933667 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 933670 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933671 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 933671 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933671 T4188 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 933674 T4188 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> 933674 T4188 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 933675 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 933676 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933676 T4191 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18f2852 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 933676 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 933677 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 933679 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 933682 T4191 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 933682 T4182 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 933684 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933684 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 933685 T4188 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> 933685 T4188 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 933686 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933688 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 933788 T4191 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> 933788 T4182 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> 933889 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 933892 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933892 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933892 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933893 T4188 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 933894 T4188 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> 933894 T4188 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 933894 T4188 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 933896 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 933998 T4182 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> 933998 T4191 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> 934392 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 934397 T4182 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934397 T4191 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934398 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934400 T4191 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 934404 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934404 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934404 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934405 T4188 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934407 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934509 T4191 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> 934600 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934602 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 934603 T4193 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bb6049 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 934603 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 934604 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 934606 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 934610 T4191 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 934610 T4193 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 934612 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 934612 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934612 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934613 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934614 T4188 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934614 T4188 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> 934614 T4188 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934616 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934616 T4191 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934616 T4193 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934617 T4193 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 934618 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 934618 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934619 T4188 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> 934619 T4188 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934623 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934625 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 934626 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934626 T4195 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f49c55 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 934626 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 934627 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 934628 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 934630 T4193 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 934630 T4195 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 934631 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934631 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 934632 T4188 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> 934632 T4188 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934633 T4186 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934635 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934687 T4178 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 934688 T4178 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 934689 T4197 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17b18d3 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 934689 T4178 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 934690 T4188 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57744_solr
[junit4] 2> 934691 T4198 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> 934692 T4178 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57744_solr
[junit4] 2> 934692 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 934693 T4178 oasc.Overseer.start Overseer (id=91697227054383113-127.0.0.1:57744_solr-n_0000000002) starting
[junit4] 2> 934702 T4200 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 934703 T4200 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57744_solr
[junit4] 2> 934703 T4199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934704 T4199 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 934704 T4199 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> 934704 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934705 T4195 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> 934705 T4193 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> 934708 T4199 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> 934708 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934709 T4193 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> 934709 T4195 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> 934714 T4195 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> 934714 T4193 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> 934717 T4199 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> 934718 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934719 T4195 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> 934719 T4193 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> 934721 T4199 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 934836 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934839 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934839 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 934840 T4199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934841 T4199 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> 934841 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 934843 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934844 T4195 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934844 T4193 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 934844 T4195 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> 934844 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934844 T4193 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> 934845 T4193 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 934845 T4193 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> 934845 T4195 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 934846 T4193 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> 934852 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934853 T4199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 934855 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 934957 T4195 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> 935046 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935047 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935048 T4202 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@119716c name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935048 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935050 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 935051 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 935053 T4202 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935053 T4195 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935054 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935054 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935055 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935055 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935056 T4199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935057 T4199 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> 935057 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935058 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935059 T4202 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 935060 T4202 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 935060 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935060 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935061 T4199 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> 935061 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935063 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935064 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935065 T4204 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10a3e12 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935065 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935065 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935066 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 935067 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 935070 T4202 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935070 T4204 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935073 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935073 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935074 T4199 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> 935074 T4199 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935076 T4197 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935078 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935103 T4178 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 935104 T4178 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935105 T4206 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@172a756 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935105 T4178 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935106 T4199 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57744_solr
[junit4] 2> 935106 T4207 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> 935108 T4178 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57744_solr
[junit4] 2> 935108 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 935109 T4178 oasc.Overseer.start Overseer (id=91697227054383116-127.0.0.1:57744_solr-n_0000000003) starting
[junit4] 2> 935114 T4209 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 935115 T4209 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57744_solr
[junit4] 2> 935115 T4208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935116 T4208 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 935116 T4208 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> 935116 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935117 T4202 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> 935117 T4204 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> 935121 T4208 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> 935121 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935123 T4204 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> 935123 T4202 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> 935125 T4204 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> 935125 T4202 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> 935127 T4208 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> 935127 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935128 T4202 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> 935128 T4204 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> 935130 T4208 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 935279 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935281 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935281 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935282 T4208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935283 T4208 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> 935283 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935285 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935285 T4202 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> 935285 T4204 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> 935287 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935287 T4204 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 935288 T4204 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 935290 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935291 T4208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935293 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935395 T4204 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> 935488 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935490 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935491 T4211 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42db73 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935491 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935492 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 935494 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 935496 T4204 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935496 T4211 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935497 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935497 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935497 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935498 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935499 T4208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935500 T4208 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> 935500 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935501 T4211 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 935501 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935501 T4204 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 935502 T4211 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 935503 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935503 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935504 T4208 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> 935504 T4208 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 935505 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935507 T4147 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935507 T4213 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bfd2cf name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935508 T4147 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935510 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935510 T4147 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 935512 T4147 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 935514 T4213 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935514 T4211 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 935515 T4178 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 935515 T4206 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 935515 T4147 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 935516 T4178 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 935516 T4208 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:96)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:455)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:261)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 935517 T4215 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e0b93 name:ZooKeeperConnection Watcher:127.0.0.1:57744/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 935517 T4208 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:57744_solr
[junit4] 2> 935517 T4178 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 935518 T4216 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> 935520 T4178 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57744_solr
[junit4] 2> 935520 T4147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935520 T4178 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 935522 T4178 oasc.Overseer.start Overseer (id=91697227054383119-127.0.0.1:57744_solr-n_0000000004) starting
[junit4] 2> 935527 T4218 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 935528 T4218 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:57744_solr
[junit4] 2> 935528 T4217 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 935529 T4217 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 935529 T4217 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>
[...truncated too long message...]
c.Overseer.start Overseer (id=91697228417859587-127.0.0.1:40101_solr-n_0000000000) starting
[junit4] 2> 954006 T4147 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 954012 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 954016 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 954020 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 954025 T4147 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 954032 T4687 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 954033 T4687 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:40101_solr
[junit4] 2> 954035 T4686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 954038 T4686 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 954040 T4686 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 954041 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 954048 T4686 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 954050 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 954054 T4686 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 954057 T4686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 954060 T4686 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 954062 T4685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 954063 T4679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 954138 T4674 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x145c624b6bc0000, 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> 954138 T4147 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40101 40101
[junit4] 2> 954250 T4673 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40101 40101
[junit4] 2> 954253 T4147 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 954253 T4686 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:40101_solr
[junit4] 2> 954254 T4688 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> 954256 T4147 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 954256 T4147 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 954915 T4671 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 957257 T4147 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.OverseerTest-2D7D728CDE53BBDC-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=is, timezone=America/Virgin
[junit4] 2> NOTE: Linux 3.8.0-38-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=1,free=340543624,total=523239424
[junit4] 2> NOTE: All tests run in this JVM: [TestFieldSortValues, DistributedTermsComponentTest, TestShortCircuitedRequests, SimpleFacetsTest, TestDocSet, DocExpirationUpdateProcessorFactoryTest, LegacyHTMLStripCharFilterTest, SpatialFilterTest, TestQueryUtils, StatelessScriptUpdateProcessorFactoryTest, AnalysisErrorHandlingTest, TestSerializedLuceneMatchVersion, DateMathParserTest, TestRecoveryHdfs, TestSchemaVersionResource, TestFieldResource, PrimitiveFieldTypeTest, AnalysisAfterCoreReloadTest, SuggesterFSTTest, TestJoin, TestBadConfig, TestAddFieldRealTimeGet, TestCollationKeyRangeQueries, TestManagedSynonymFilterFactory, DeleteReplicaTest, TestFieldTypeResource, TestBlendedInfixSuggestions, TestAnalyzeInfixSuggestions, LeaderElectionTest, ZkCLITest, UpdateParamsTest, HdfsLockFactoryTest, DOMUtilTest, TestSearchPerf, ResponseLogComponentTest, UnloadDistributedZkTest, TestPerFieldSimilarity, TestPHPSerializedResponseWriter, TestNoOpRegenerator, TestSolrIndexConfig, TestBM25SimilarityFactory, CircularListTest, PreAnalyzedUpdateProcessorTest, TestExpandComponent, SystemInfoHandlerTest, TestFunctionQuery, TestNRTOpen, TestSolrDeletionPolicy1, WordBreakSolrSpellCheckerTest, TestMergePolicyConfig, CacheHeaderTest, DocValuesTest, ClusterStateTest, CoreAdminHandlerTest, TestMaxScoreQueryParser, SearchHandlerTest, ShardRoutingTest, SliceStateUpdateTest, TestSurroundQueryParser, SolrInfoMBeanTest, TestCopyFieldCollectionResource, BinaryUpdateRequestHandlerTest, TestSearcherReuse, TestRemoteStreaming, TestJmxMonitoredMap, CursorMarkTest, ShowFileRequestHandlerTest, TestMiniSolrCloudCluster, DistribCursorPagingTest, SyncSliceTest, EchoParamsTest, ClusterStateUpdateTest, TestExtendedDismaxParser, TestReplicationHandler, TestSolrXMLSerializer, TestCoreContainer, TestManagedResource, OverseerCollectionProcessorTest, DirectUpdateHandlerOptimizeTest, TestCustomSort, TestInitQParser, FieldMutatingUpdateProcessorTest, PeerSyncTest, OverseerStatusTest, TestDynamicFieldResource, SolrXmlInZkTest, ConnectionManagerTest, ResourceLoaderTest, TestRequestStatusCollectionAPI, SoftAutoCommitTest, TestRandomDVFaceting, TestExceedMaxTermLength, DocumentBuilderTest, TestRestManager, BasicDistributedZkTest, CollectionsAPIDistributedZkTest, OverseerTest]
[junit4] Completed on J0 in 30.30s, 9 tests, 1 error <<< FAILURES!
[...truncated 602 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/lucene/common-build.xml:1297: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/lucene/common-build.xml:921: There were test failures: 389 suites, 1627 tests, 1 error, 37 ignored (16 assumptions)
Total time: 67 minutes 15 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b14 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure