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/03/11 10:11:26 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 9646
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9646/
Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([AC1F04A29B94706D:A8178B5189319F4C]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
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.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
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)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 47 more
Build Log:
[...truncated 9598 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 222242 T1045 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 222242 T1045 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-1394527911145
[junit4] 2> 222242 T1045 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 222246 T1045 oas.SolrTestCaseJ4.setUp ###Starting testPlaceholders
[junit4] 2> 222246 T1045 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 222247 T1046 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 222347 T1045 oasc.ZkTestServer.run start zk server on port:36836
[junit4] 2> 222348 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222445 T1052 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c970d5b name:ZooKeeperConnection Watcher:127.0.0.1:36836/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222446 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222446 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222449 T1054 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12d574fe name:ZooKeeperConnection Watcher:127.0.0.1:36836 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222449 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222451 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222452 T1056 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@165abd4a name:ZooKeeperConnection Watcher:127.0.0.1:36836 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222453 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222453 T1045 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 222457 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 222460 T1045 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 222465 T1045 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 222468 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 222474 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222475 T1058 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c8b952c name:ZooKeeperConnection Watcher:127.0.0.1:36836/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222475 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222477 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 222480 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 222484 T1052 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 222485 T1058 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 222485 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222487 T1060 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7385c043 name:ZooKeeperConnection Watcher:127.0.0.1:36836/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222487 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222488 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 222491 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 222496 T1045 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36836_solr
[junit4] 2> 222496 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 222499 T1045 oasc.Overseer.start Overseer (id=91391781185191940-127.0.0.1:36836_solr-n_0000000000) starting
[junit4] 2> 222501 T1045 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 222506 T1045 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 222511 T1045 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 222515 T1062 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 222518 T1062 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 222518 T1061 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 222522 T1061 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 222523 T1061 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=12 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"12",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 222523 T1061 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3, shard4, shard5, shard6, shard7, shard8, shard9, shard10, shard11, shard12]
[junit4] 2> 222523 T1061 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 222526 T1060 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 222528 T1052 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> 222528 T1058 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> 223019 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 223043 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 223058 T1060 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 223061 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223065 T1061 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223069 T1052 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 223070 T1058 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 223075 T1045 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:36836 36836
[junit4] 2> 223137 T1045 oas.SolrTestCaseJ4.tearDown ###Ending testPlaceholders
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 223144 T1045 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 223144 T1045 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 223145 T1063 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 223245 T1045 oasc.ZkTestServer.run start zk server on port:43962
[junit4] 2> 223245 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 223254 T1069 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1acd252a name:ZooKeeperConnection Watcher:127.0.0.1:43962/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 223255 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 223256 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 223259 T1071 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4804471c name:ZooKeeperConnection Watcher:127.0.0.1:43962 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 223259 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 223290 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 223291 T1073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ee91c43 name:ZooKeeperConnection Watcher:127.0.0.1:43962 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 223291 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 223292 T1045 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 223296 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 223299 T1045 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 223302 T1045 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 223305 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 223309 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 223310 T1075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44d7d0c1 name:ZooKeeperConnection Watcher:127.0.0.1:43962/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 223311 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 223312 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 223315 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 223320 T1045 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43962_solr
[junit4] 2> 223321 T1045 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 223324 T1045 oasc.Overseer.start Overseer (id=91391781244305411-127.0.0.1:43962_solr-n_0000000000) starting
[junit4] 2> 223327 T1045 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 223331 T1045 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 223336 T1045 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 223340 T1077 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 223341 T1077 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 223342 T1076 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 223344 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223346 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223347 T1076 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 223347 T1076 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 223353 T1075 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 223355 T1069 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> 223397 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223401 T1075 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 223403 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 223404 T1076 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 223404 T1076 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 223404 T1076 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 223408 T1075 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 223510 T1069 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> 223554 T1045 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:43962 43962
[junit4] 2> 224041 T1045 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 224046 T1045 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 224047 T1045 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 224047 T1078 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 224147 T1045 oasc.ZkTestServer.run start zk server on port:48063
[junit4] 2> 224148 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224152 T1084 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5601015a name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224153 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224153 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224155 T1086 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52ea8917 name:ZooKeeperConnection Watcher:127.0.0.1:48063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224155 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224176 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224178 T1088 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ae58bea name:ZooKeeperConnection Watcher:127.0.0.1:48063 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224178 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224179 T1045 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 224182 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 224186 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224187 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224187 T1092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a033c59 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224188 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224188 T1093 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17a7cef1 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224188 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224189 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 224189 T1045 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 224194 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 224194 T1045 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 224198 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 224202 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 224202 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 224203 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 224206 T1089 oasc.Overseer.start Overseer (id=91391781303418883-127.0.0.1:48063_solr-n_0000000000) starting
[junit4] 2> 224209 T1093 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 224210 T1089 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 224211 T1045 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 224216 T1089 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 224221 T1089 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 224224 T1089 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 224224 T1095 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 224227 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224228 T1097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@46d60d72 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224228 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224229 T1095 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91391781303418883-127.0.0.1:48063_solr-n_0000000000) am no longer a leader.
[junit4] 2> 224229 T1095 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 224230 T1095 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:225)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:222)
[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:222)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:234)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:185)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 224238 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 224238 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 224241 T1089 oasc.Overseer.start Overseer (id=91391781303418885-127.0.0.1:48063_solr-n_0000000001) starting
[junit4] 2> 224248 T1099 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 224249 T1099 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 224250 T1098 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 224253 T1098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224254 T1098 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> 224254 T1098 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 224254 T1098 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 224258 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224259 T1093 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> 224716 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 224731 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 224739 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224743 T1098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224743 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224743 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 224750 T1098 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> 224751 T1098 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 224754 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 224755 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224756 T1101 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3d7bc2dd name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 224756 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 224758 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 224761 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 224765 T1093 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 224765 T1101 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 224768 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224768 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 224770 T1098 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> 224770 T1098 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 224776 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224781 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224879 T1093 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> 224880 T1101 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> 224984 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224989 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224989 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224990 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 224993 T1098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224994 T1098 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> 224994 T1098 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 224995 T1098 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 225001 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225106 T1093 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> 225106 T1101 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> 225490 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 225501 T1101 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 225501 T1093 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 225503 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225504 T1101 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 225511 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225511 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225511 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225513 T1098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225518 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225622 T1101 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> 225706 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225707 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 225709 T1103 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bb1f4fc name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 225709 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 225710 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 225714 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 225718 T1101 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 225718 T1103 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 225721 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225721 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 225721 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225721 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225724 T1098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225726 T1098 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> 225726 T1098 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 225730 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225734 T1103 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 225734 T1101 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 225737 T1103 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 225738 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225738 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 225740 T1098 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> 225740 T1098 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 225750 T1089 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 225750 T1097 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225752 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 225753 T1105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6574f7a7 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 225753 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 225759 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 225760 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 225760 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 225760 T1107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@275ad01a name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 225760 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 225763 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 225764 T1089 oasc.Overseer.start Overseer (id=91391781303418888-127.0.0.1:48063_solr-n_0000000002) starting
[junit4] 2> 225767 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 225772 T1107 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 225773 T1103 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 225774 T1109 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 225775 T1109 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 225776 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 225778 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225780 T1108 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 225781 T1108 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> 225781 T1108 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 225782 T1103 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> 225782 T1107 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> 225792 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225793 T1108 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> 225794 T1108 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 225795 T1103 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> 225795 T1107 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> 225801 T1108 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 225804 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225808 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225809 T1103 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> 225809 T1107 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> 225816 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225816 T1108 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> 225817 T1108 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 225820 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225923 T1107 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> 225924 T1103 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> 225995 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 225999 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225999 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226000 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 225999 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226003 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226004 T1108 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> 226004 T1108 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226009 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226013 T1107 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226014 T1103 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226016 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226017 T1107 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 226024 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226028 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226131 T1107 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> 226218 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226220 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226222 T1111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47bfc16d name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226222 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226225 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 226232 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 226240 T1107 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226240 T1111 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226245 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226246 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226246 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226246 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226251 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226254 T1108 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> 226254 T1108 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226262 T1105 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226271 T1111 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226272 T1107 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226274 T1089 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 226278 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226279 T1111 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 226280 T1113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a077792 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226281 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226285 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226292 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 226293 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 226301 T1089 oasc.Overseer.start Overseer (id=91391781303418891-127.0.0.1:48063_solr-n_0000000003) starting
[junit4] 2> 226317 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226319 T1117 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 226320 T1116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@590d902c name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226328 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226330 T1117 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 226333 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 226339 T1114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226342 T1114 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 226345 T1114 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> 226345 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 226346 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226349 T1111 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> 226350 T1116 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> 226360 T1111 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226361 T1114 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 226362 T1116 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226370 T1114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226370 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226371 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226372 T1114 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> 226372 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226382 T1116 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> 226382 T1111 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> 226392 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226393 T1114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226397 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226398 T1114 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> 226398 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226402 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226506 T1116 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> 226507 T1111 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> 226595 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226602 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226603 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226603 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226603 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226609 T1114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226611 T1114 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> 226612 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226621 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226630 T1116 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226630 T1111 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226635 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226637 T1116 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 226650 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226660 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226765 T1116 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> 226838 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226840 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226841 T1119 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20e10434 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226842 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226843 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 226847 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 226851 T1116 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226851 T1119 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226856 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226856 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226856 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226856 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226860 T1114 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226861 T1114 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> 226861 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226866 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226871 T1119 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226871 T1116 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 226874 T1119 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 226875 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226875 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226877 T1114 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> 226877 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226882 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226885 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226889 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226891 T1121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b12d1c9 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226891 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226891 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226893 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 226896 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 226900 T1119 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226900 T1121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 226904 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226904 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 226906 T1114 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> 226906 T1114 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226911 T1113 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 226916 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226919 T1089 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 226921 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 226922 T1123 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@726b5b3c name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 226923 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 226932 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 226932 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 226935 T1089 oasc.Overseer.start Overseer (id=91391781303418895-127.0.0.1:48063_solr-n_0000000004) starting
[junit4] 2> 226942 T1125 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 226943 T1125 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 226945 T1124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 226946 T1124 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 226947 T1124 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> 226947 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226948 T1121 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> 226949 T1119 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> 226954 T1124 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> 226954 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226955 T1121 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> 226956 T1119 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> 226962 T1121 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> 226962 T1119 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> 226969 T1124 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> 226969 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 226970 T1119 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> 226970 T1121 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> 226975 T1124 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 227002 T1093 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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[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> 227002 T1093 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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[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> 227118 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227123 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227124 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 227128 T1124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227130 T1124 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> 227131 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227136 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227137 T1121 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> 227137 T1119 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> 227143 T1121 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 227143 T1119 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 227146 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227146 T1121 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 227154 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227156 T1124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227161 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227265 T1121 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> 227348 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227350 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 227351 T1127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@471a08b5 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 227351 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 227353 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 227358 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 227363 T1121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 227364 T1127 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 227367 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227367 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227367 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227367 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 227369 T1124 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227371 T1124 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> 227371 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227375 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227379 T1127 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 227380 T1121 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 227382 T1127 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 227383 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227383 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 227386 T1124 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> 227386 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227390 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227394 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227398 T1045 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 227400 T1129 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@422d228c name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 227400 T1045 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 227402 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227402 T1045 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 227406 T1045 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 227409 T1127 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 227409 T1129 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 227412 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227413 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 227415 T1124 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> 227415 T1124 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227419 T1123 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 227423 T1045 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227442 T1089 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 227443 T1089 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 227445 T1131 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76094ed7 name:ZooKeeperConnection Watcher:127.0.0.1:48063/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 227445 T1089 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 227450 T1089 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48063_solr
[junit4] 2> 227450 T1089 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 227453 T1089 oasc.Overseer.start Overseer (id=91391781303418898-127.0.0.1:48063_solr-n_0000000005) starting
[junit4] 2> 227460 T1133 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 227466 T1133 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 227469 T1132 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 227470 T1132 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 227470 T1132 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> 227471 T1132 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227472 T1129 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> 227473 T1127 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> 227478 T1132 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> 227479 T1132 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227480 T1129 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> 227480 T1127 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> 227486 T1127 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> 227486 T1129 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> 227493 T1132 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> 227493 T1132 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 227494 T1129 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> 227494 T1127 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> 227498 T1132 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 227514 T1103 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:259)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[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:256)
[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> 227515 T1103 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.
[...truncated too long message...]
common.cloud.SolrZkClient.clean(SolrZkClient.java:635)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:630)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:976)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:253)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:202)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 254319 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 254328 T1465 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254340 T1465 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254343 T1466 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 254343 T1459 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 254351 T1465 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254355 T1465 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254357 T1466 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 254360 T1465 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 254468 T1459 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> 254468 T1457 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> 255343 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 256352 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 257360 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 258367 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 259375 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 260398 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 261407 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 262415 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 263420 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 264428 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 265432 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 266437 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 267441 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 268446 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 269453 T1045 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 269460 T1457 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 269460 T1459 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 269464 T1045 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42440 42440
[junit4] 2> 269610 T1045 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=AC1F04A29B94706D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_GB -Dtests.timezone=America/Antigua -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 18.6s J0 | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([AC1F04A29B94706D:A8178B5189319F4C]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:666)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
[junit4] > ... 46 more
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:431)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:428)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:385)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:372)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 47 more
[junit4] 2> 269642 T1045 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 269642 T1045 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 272642 T1045 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=DefaultSimilarity, locale=en_GB, timezone=America/Antigua
[junit4] 2> NOTE: Linux 3.8.0-36-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=1,free=86897528,total=155328512
[junit4] 2> NOTE: All tests run in this JVM: [TestCustomSort, ClusterStateTest, SuggesterTest, TermsComponentTest, TestRealTimeGet, TestSearchPerf, MBeansHandlerTest, TestManagedSchema, TestReversedWildcardFilterFactory, CoreAdminHandlerTest, TestLFUCache, MigrateRouteKeyTest, TestBM25SimilarityFactory, TestMaxScoreQueryParser, ZkControllerTest, SolrXmlInZkTest, ShardRoutingTest, TestPseudoReturnFields, RegexBoostProcessorTest, TestSolrDeletionPolicy1, SolrCoreTest, DOMUtilTest, OverseerRolesTest, CacheHeaderTest, LukeRequestHandlerTest, DeleteShardTest, OverseerTest]
[junit4] Completed on J0 in 50.43s, 9 tests, 1 error <<< FAILURES!
[...truncated 1012 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:473: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: 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:490: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:911: There were test failures: 369 suites, 1581 tests, 1 error, 37 ignored (8 assumptions)
Total time: 46 minutes 8 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure