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/02/01 06:40:39 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 9213
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9213/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([19C1D899553FACF7:1DC9576A479A43D6]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:428)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9550 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 172872 T1332 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1391232057876
[junit4] 2> 172873 T1332 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 172875 T1332 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 172876 T1332 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 172876 T1333 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 172976 T1332 oasc.ZkTestServer.run start zk server on port:41786
[junit4] 2> 172977 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173057 T1339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61220ed4 name:ZooKeeperConnection Watcher:127.0.0.1:41786/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173058 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173058 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173061 T1341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@647edd33 name:ZooKeeperConnection Watcher:127.0.0.1:41786 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173061 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173064 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173065 T1343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d380be8 name:ZooKeeperConnection Watcher:127.0.0.1:41786 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173065 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173066 T1332 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 173072 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 173076 T1332 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 173079 T1332 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 173082 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 173087 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173089 T1345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e9637fe name:ZooKeeperConnection Watcher:127.0.0.1:41786/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173089 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173091 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 173095 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 173100 T1339 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 173100 T1345 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 173101 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173102 T1347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d7e76b3 name:ZooKeeperConnection Watcher:127.0.0.1:41786/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173103 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173104 T1332 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 173108 T1332 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 173114 T1332 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:41786_solr
[junit4] 2> 173115 T1332 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 173118 T1332 oasc.Overseer.start Overseer (id=91175784145289220-127.0.0.1:41786_solr-n_0000000000) starting
[junit4] 2> 173121 T1332 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 173128 T1332 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 173133 T1332 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 173137 T1349 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 173139 T1349 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 173140 T1348 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 173145 T1348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 173146 T1348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 173146 T1348 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 173146 T1348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 173150 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173151 T1345 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> 173151 T1339 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> 173642 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 173671 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 173692 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173695 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 173699 T1348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 173706 T1339 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 173709 T1345 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 173713 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173714 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 173717 T1351 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f57d954 name:ZooKeeperConnection Watcher:127.0.0.1:41786/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 173717 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 173721 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 173730 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 173738 T1339 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 173738 T1351 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 173745 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173745 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 173750 T1348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 173750 T1348 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 173760 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173768 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 173784 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173797 T1347 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 173902 T1351 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> 173903 T1339 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> 173906 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 173911 T1339 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 173911 T1351 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 173914 T1332 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:41786 41786
[junit4] 2> 174001 T1332 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 174005 T1332 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 174006 T1332 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 174006 T1352 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 174106 T1332 oasc.ZkTestServer.run start zk server on port:55887
[junit4] 2> 174107 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174110 T1358 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f123549 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174110 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174110 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174112 T1360 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e0be922 name:ZooKeeperConnection Watcher:127.0.0.1:55887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174112 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174156 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174157 T1362 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d19dc64 name:ZooKeeperConnection Watcher:127.0.0.1:55887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174157 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174157 T1332 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 174162 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 174171 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174172 T1365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1caae1f3 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174173 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174173 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 174174 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174175 T1367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e3ceb07 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174175 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174177 T1332 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 174178 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 174182 T1332 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 174185 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 174188 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 174188 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 174191 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 174193 T1363 oasc.Overseer.start Overseer (id=91175784219541507-127.0.0.1:55887_solr-n_0000000000) starting
[junit4] 2> 174197 T1367 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 174197 T1363 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 174200 T1332 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 174204 T1363 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 174209 T1363 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 174213 T1363 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 174213 T1369 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 174214 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174215 T1371 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d4987e8 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174216 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174220 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 174220 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 174224 T1363 oasc.Overseer.start Overseer (id=91175784219541509-127.0.0.1:55887_solr-n_0000000001) starting
[junit4] 2> 174232 T1373 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 174233 T1373 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 174234 T1372 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 174238 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 174239 T1372 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> 174239 T1372 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 174239 T1372 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 174243 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174244 T1367 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> 174705 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 174720 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 174729 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174733 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 174734 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174734 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 174745 T1372 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> 174745 T1372 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 174751 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 174752 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174753 T1375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36fce9d7 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 174753 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 174756 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 174764 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 174771 T1367 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 174771 T1375 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 174776 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174776 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 174778 T1372 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> 174778 T1372 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 174783 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 174788 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 174889 T1375 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> 174889 T1367 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> 174992 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175000 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175001 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175001 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175006 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175008 T1372 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> 175008 T1372 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 175008 T1372 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 175016 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175122 T1375 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> 175123 T1367 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> 175501 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 175519 T1375 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 175520 T1367 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 175524 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175537 T1375 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 175551 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175551 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175552 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175556 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175561 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175664 T1375 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> 175714 T1369 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:350)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:164)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 175714 T1369 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91175784219541507-127.0.0.1:55887_solr-n_0000000000) am no longer a leader.
[junit4] 2> 175714 T1369 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 175714 T1368 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 175714 T1369 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:222)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:219)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:219)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:220)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:171)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 175716 T1369 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[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:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:350)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:178)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 175716 T1369 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91175784219541507-127.0.0.1:55887_solr-n_0000000000) am no longer a leader.
[junit4] 2> 175739 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175741 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 175742 T1377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e2291d name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 175743 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 175745 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 175750 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 175756 T1375 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 175756 T1377 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 175759 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175759 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175759 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 175760 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175764 T1372 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175765 T1372 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> 175765 T1372 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 175770 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175776 T1377 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 175776 T1375 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 175779 T1377 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 175781 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175781 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 175784 T1372 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> 175784 T1372 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 175834 T1363 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 175917 T1371 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 175920 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 175923 T1379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49b40272 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 175923 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 175935 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 175937 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 175938 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 175938 T1381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f1a4fad name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 175939 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 175944 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 175949 T1363 oasc.Overseer.start Overseer (id=91175784219541512-127.0.0.1:55887_solr-n_0000000002) starting
[junit4] 2> 175957 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 175969 T1383 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 175970 T1377 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 175972 T1381 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 175973 T1383 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 175982 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 175987 T1382 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 175990 T1382 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 175992 T1382 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> 175992 T1382 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 175995 T1381 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> 175995 T1377 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> 176013 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176014 T1382 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> 176014 T1382 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176016 T1381 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> 176017 T1377 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> 176027 T1382 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 176033 T1382 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176044 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176047 T1381 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> 176047 T1377 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> 176064 T1382 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176066 T1382 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> 176066 T1382 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176074 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176180 T1381 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> 176180 T1377 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> 176217 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176225 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176225 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176225 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176225 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 176232 T1382 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176235 T1382 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> 176235 T1382 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176245 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176256 T1381 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176256 T1377 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176262 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176264 T1381 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 176281 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176292 T1379 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176399 T1381 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> 176467 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176470 T1363 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 176470 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 176473 T1385 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e7edcb7 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 176473 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 176473 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 176476 T1387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c0bb03 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 176476 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 176479 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 176489 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 176490 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 176492 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 176500 T1363 oasc.Overseer.start Overseer (id=91175784219541515-127.0.0.1:55887_solr-n_0000000003) starting
[junit4] 2> 176504 T1381 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 176507 T1385 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 176517 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 176523 T1389 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 176528 T1389 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 176529 T1388 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 176544 T1388 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176546 T1388 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> 176547 T1388 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176553 T1385 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176555 T1381 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176558 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176566 T1385 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 176569 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 176582 T1388 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176584 T1388 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> 176585 T1388 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176595 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176600 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176600 T1385 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> 176606 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 176609 T1391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5497d017 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 176610 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 176616 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 176617 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176626 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 176634 T1385 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 176634 T1391 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 176638 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176638 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 176640 T1388 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> 176641 T1388 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176646 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176651 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176752 T1391 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> 176752 T1385 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> 176854 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176862 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176862 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176862 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 176862 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176870 T1388 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176873 T1388 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> 176874 T1388 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 176884 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176896 T1391 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176897 T1385 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 176903 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 176905 T1391 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 176917 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 176923 T1387 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177021 T1367 oasc.LeaderElector$1.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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 177022 T1367 oasc.LeaderElector$1.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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 177027 T1391 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> 177107 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177109 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177111 T1393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ca23ad name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177111 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177115 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 177119 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 177123 T1363 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 177125 T1393 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177126 T1391 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177127 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177129 T1395 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a635f47 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177129 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177131 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177136 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 177137 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 177141 T1363 oasc.Overseer.start Overseer (id=91175784219541518-127.0.0.1:55887_solr-n_0000000004) starting
[junit4] 2> 177149 T1393 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177150 T1391 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177152 T1393 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 177154 T1397 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 177157 T1397 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 177157 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177157 T1396 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 177163 T1396 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177164 T1396 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> 177164 T1396 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177168 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177171 T1393 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> 177173 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177175 T1399 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fd81a3 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177175 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177177 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 177179 T1396 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177181 T1396 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> 177181 T1396 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177183 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 177186 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177188 T1393 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177189 T1399 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177193 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177193 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177197 T1396 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> 177197 T1396 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177203 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177207 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177307 T1393 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> 177307 T1399 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> 177409 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177414 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177414 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177414 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177414 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177417 T1396 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177418 T1396 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> 177419 T1396 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177419 T1372 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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 177424 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177430 T1399 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177430 T1393 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177432 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177436 T1399 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 177443 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177450 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177554 T1399 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> 177635 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177637 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177638 T1401 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d88c3cf name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177638 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177640 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 177645 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 177649 T1399 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177649 T1401 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177653 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177653 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177653 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177653 T1395 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177655 T1363 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 177657 T1363 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177658 T1403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2de9fae7 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177658 T1363 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177665 T1363 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55887_solr
[junit4] 2> 177665 T1363 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 177670 T1363 oasc.Overseer.start Overseer (id=91175784219541521-127.0.0.1:55887_solr-n_0000000005) starting
[junit4] 2> 177671 T1401 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177671 T1399 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177675 T1401 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 177678 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177682 T1405 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 177684 T1405 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 177685 T1404 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 177692 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177693 T1404 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177694 T1404 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> 177694 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177696 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 177697 T1407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79194cf5 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 177698 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 177702 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 177704 T1401 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> 177705 T1407 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> 177721 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 177724 T1404 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177726 T1404 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> 177726 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177727 T1401 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177727 T1407 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 177732 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177732 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177741 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177745 T1404 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> 177745 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177747 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177750 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177759 T1377 oasc.LeaderElector$1.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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 177760 T1377 oasc.LeaderElector$1.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:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[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:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 177853 T1407 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> 177853 T1401 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> 177950 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177954 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177954 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177954 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 177954 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177957 T1404 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177958 T1404 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> 177958 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 177974 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 177981 T1407 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177982 T1401 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 177984 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 177985 T1407 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 178016 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178023 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178126 T1407 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> 178187 T1332 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 178188 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 178190 T1409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2806a765 name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 178190 T1332 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 178192 T1332 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 178196 T1332 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 178201 T1407 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 178202 T1409 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 178205 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178205 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178206 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178206 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 178209 T1404 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 178210 T1404 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> 178210 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 178215 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178220 T1409 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 178220 T1407 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 178223 T1409 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 178225 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178225 T1332 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 178227 T1404 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> 178227 T1404 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 178232 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178237 T1403 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 178240 T1332 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 178242 T1411 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c9da2ea name:ZooKeeperConnection Watcher:127.0.0.1:55887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 178242 T1332 oascc.ConnectionManager.waitForConnected Client is connected to Zoo
[...truncated too long message...]
I am going to be the leader 127.0.0.1:40876_solr
[junit4] 2> 202751 T1332 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 202754 T1332 oasc.Overseer.start Overseer (id=91175786091184131-127.0.0.1:40876_solr-n_0000000000) starting
[junit4] 2> 202756 T1332 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 202762 T1332 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 202765 T1779 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 202767 T1779 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 202769 T1778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 202770 T1778 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 202771 T1778 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> 202772 T1771 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> 202776 T1778 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> 202777 T1771 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> 202780 T1778 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 202782 T1778 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 202783 T1778 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> 202786 T1777 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 202788 T1771 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> 202874 T1332 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40876 40876
[junit4] 2> 202978 T1332 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 202981 T1332 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 202981 T1332 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 203874 T1688 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 203875 T1688 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 203882 T1690 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 203883 T1690 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 205982 T1332 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=en_IE, timezone=Asia/Chongqing
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=69148728,total=275316736
[junit4] 2> NOTE: All tests run in this JVM: [OverseerRolesTest, BasicFunctionalityTest, BJQParserTest, SimpleFacetsTest, UpdateParamsTest, SuggesterTest, UpdateRequestProcessorFactoryTest, TestBadConfig, TestSolrXml, TestSort, TestAddFieldRealTimeGet, SliceStateUpdateTest, SoftAutoCommitTest, LeaderElectionTest, QueryElevationComponentTest, SpatialFilterTest, MBeansHandlerTest, TestSchemaNameResource, SolrCoreTest, SOLR749Test, AutoCommitTest, TestClassNameShortening, URLClassifyProcessorTest, TestFunctionQuery, TestReplicationHandler, InfoHandlerTest, SliceStateTest, CacheHeaderTest, TestSolrQueryParserResource, TestRandomMergePolicy, TestDocumentBuilder, FileBasedSpellCheckerTest, OverseerTest]
[junit4] Completed on J0 in 33.14s, 8 tests, 1 error <<< FAILURES!
[...truncated 910 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 355 suites, 1549 tests, 1 error, 35 ignored (7 assumptions)
Total time: 45 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure