You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/16 01:46:38 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 9382
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9382/
Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
4 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion
Error Message:
ERROR: SolrIndexSearcher opens=19 closes=17
Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=19 closes=17
at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:387)
at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:155)
at sun.reflect.GeneratedMethodAccessor47.invoke(Unknown Source)
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$5.evaluate(RandomizedRunner.java:700)
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)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion
Error Message:
2 threads leaked from SUITE scope at org.apache.solr.cloud.TestDistribDocBasedVersion: 1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917) at java.lang.Thread.run(Thread.java:662) 2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917) at java.lang.Thread.run(Thread.java:662)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.TestDistribDocBasedVersion:
1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
at java.lang.Thread.run(Thread.java:662)
2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
at java.lang.Thread.run(Thread.java:662)
at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestDistribDocBasedVersion
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917) at java.lang.Thread.run(Thread.java:662) 2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917) at java.lang.Thread.run(Thread.java:662)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
at java.lang.Thread.run(Thread.java:662)
2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
at java.lang.Thread.run(Thread.java:662)
at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B:DBE1C246712A6A1A]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:429)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:426)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:383)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:370)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9957 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 721366 T3090 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
[junit4] 2> 721367 T3090 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-1392510529937
[junit4] 2> 721367 T3090 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 721371 T3090 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 721371 T3090 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 721372 T3091 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 721472 T3090 oasc.ZkTestServer.run start zk server on port:38275
[junit4] 2> 721473 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721481 T3097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d8cb3fd name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721482 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721483 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721485 T3099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67c2a88 name:ZooKeeperConnection Watcher:127.0.0.1:38275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721486 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721491 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721494 T3101 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6132a9c0 name:ZooKeeperConnection Watcher:127.0.0.1:38275 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721494 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721495 T3090 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 721503 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 721510 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721511 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721513 T3104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@464d5a85 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721514 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721514 T3106 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a94fc27 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721515 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721516 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 721519 T3090 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 721526 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 721532 T3090 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 721540 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 721545 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 721545 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 721551 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 721551 T3102 oasc.Overseer.start Overseer (id=91259570090409987-127.0.0.1:38275_solr-n_0000000000) starting
[junit4] 2> 721555 T3102 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 721556 T3106 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 721559 T3090 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 721562 T3102 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 721568 T3102 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 721572 T3108 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 721572 T3102 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 721573 T3108 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 721574 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 721577 T3110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cccdb7d name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 721577 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 721581 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 721581 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 721585 T3102 oasc.Overseer.start Overseer (id=91259570090409989-127.0.0.1:38275_solr-n_0000000001) starting
[junit4] 2> 721595 T3112 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 721596 T3112 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 721597 T3111 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 721601 T3111 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 721602 T3111 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> 721602 T3111 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 721603 T3111 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 721607 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 721608 T3106 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> 722065 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 722082 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 722094 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722098 T3111 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722099 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 722099 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722108 T3111 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> 722108 T3111 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 722113 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 722113 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722114 T3114 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3625cfff name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 722114 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 722116 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 722119 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 722124 T3106 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 722125 T3114 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 722127 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722128 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 722130 T3111 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> 722130 T3111 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 722135 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722153 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722240 T3106 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> 722240 T3114 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> 722355 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722360 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722360 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722361 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722363 T3111 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722364 T3111 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> 722364 T3111 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 722364 T3111 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 722368 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722472 T3106 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> 722472 T3114 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> 722861 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 722872 T3114 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 722872 T3106 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 722875 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722875 T3114 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 722882 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722882 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722882 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 722885 T3111 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 722890 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723003 T3114 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> 723073 T3107 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 723073 T3108 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:223)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:220)
[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:220)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:227)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:178)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 723076 T3108 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:357)
[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> 723076 T3108 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91259570090409987-127.0.0.1:38275_solr-n_0000000000) am no longer a leader.
[junit4] 2> 723077 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723080 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723082 T3116 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7499fbf name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723083 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723084 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 723088 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 723092 T3114 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723093 T3116 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723095 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723096 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723096 T3110 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723096 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723096 T3102 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 723099 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723101 T3118 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34919bd0 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723101 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723109 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 723109 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 723113 T3116 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723114 T3114 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723116 T3102 oasc.Overseer.start Overseer (id=91259570090409992-127.0.0.1:38275_solr-n_0000000002) starting
[junit4] 2> 723119 T3116 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 723124 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723128 T3120 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 723130 T3120 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 723132 T3119 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 723139 T3119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723140 T3119 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> 723140 T3119 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723141 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723142 T3122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1557a9ac name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723142 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723145 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723145 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 723147 T3116 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> 723148 T3122 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> 723154 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 723158 T3119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723159 T3119 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> 723159 T3119 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723160 T3116 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723161 T3122 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723166 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723166 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723173 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723176 T3119 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> 723176 T3119 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723179 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723181 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723286 T3116 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> 723287 T3122 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> 723382 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723386 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723386 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723386 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723387 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723402 T3119 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723403 T3119 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> 723403 T3119 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723408 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723412 T3122 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723413 T3116 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723416 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723416 T3122 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 723423 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723430 T3118 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723537 T3122 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> 723619 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723621 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723624 T3124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1352c0c4 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723625 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723628 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 723628 T3102 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 723632 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723635 T3126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4686bcd7 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723636 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723641 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 723648 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 723649 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 723653 T3122 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723655 T3124 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723662 T3102 oasc.Overseer.start Overseer (id=91259570090409995-127.0.0.1:38275_solr-n_0000000003) starting
[junit4] 2> 723664 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723679 T3128 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 723684 T3128 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 723685 T3127 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 723699 T3124 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723701 T3122 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723701 T3127 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723703 T3127 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> 723703 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723706 T3124 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 723710 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723712 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723723 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723724 T3124 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> 723725 T3127 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723726 T3127 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> 723726 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723728 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 723730 T3130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@603fd66 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 723730 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 723732 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 723738 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723738 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 723742 T3124 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723742 T3130 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 723745 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723746 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723748 T3127 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> 723748 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723754 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723759 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723859 T3130 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> 723859 T3124 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> 723962 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723966 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723967 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723967 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723967 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 723970 T3127 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723972 T3127 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> 723972 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 723977 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 723986 T3124 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723986 T3130 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 723988 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 723990 T3130 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 723999 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724004 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724108 T3130 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> 724192 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724193 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724197 T3132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@148db4f2 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724197 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724200 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 724204 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 724209 T3130 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724209 T3132 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724212 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724212 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724212 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724212 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724216 T3127 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724218 T3127 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> 724218 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724223 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724227 T3132 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724227 T3130 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724230 T3132 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 724231 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724231 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724233 T3127 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> 724234 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724238 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724245 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724248 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724250 T3134 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16b415b2 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724250 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724252 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724253 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 724257 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 724261 T3132 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724262 T3134 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724265 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724265 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724267 T3127 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> 724267 T3127 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724272 T3126 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724277 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724280 T3102 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 724281 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724283 T3136 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e5de96a name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724283 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724288 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 724289 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 724293 T3102 oasc.Overseer.start Overseer (id=91259570090409999-127.0.0.1:38275_solr-n_0000000004) starting
[junit4] 2> 724300 T3138 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 724302 T3138 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 724315 T3137 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724317 T3137 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 724318 T3137 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> 724318 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724320 T3134 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> 724321 T3132 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> 724326 T3137 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> 724326 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724327 T3134 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> 724328 T3132 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> 724334 T3134 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> 724334 T3132 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> 724339 T3137 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> 724339 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724341 T3134 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> 724341 T3132 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> 724345 T3137 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 724373 T3106 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[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> 724374 T3127 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 724374 T3106 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[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> 724479 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724484 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724484 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724488 T3137 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724490 T3137 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> 724490 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724497 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724498 T3132 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> 724499 T3134 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> 724506 T3132 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724507 T3134 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724508 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724511 T3134 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 724518 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724521 T3137 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724525 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724599 T3111 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue/qn-0000000006
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:271)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:428)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:391)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:163)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 724628 T3134 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> 724711 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724713 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724714 T3140 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37475ba1 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724714 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724716 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 724720 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 724724 T3134 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724724 T3140 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724728 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724728 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724728 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724729 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724732 T3137 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724733 T3137 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> 724733 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724738 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724742 T3140 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724742 T3134 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 724745 T3140 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 724747 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724747 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724749 T3137 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> 724749 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724755 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724759 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724763 T3090 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724764 T3142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@effe4e8 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724765 T3090 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724767 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724767 T3090 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 724771 T3090 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 724775 T3140 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724775 T3142 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 724778 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724778 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 724780 T3137 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> 724781 T3137 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724785 T3136 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724791 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724800 T3102 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 724802 T3102 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 724803 T3144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e44e848 name:ZooKeeperConnection Watcher:127.0.0.1:38275/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 724803 T3102 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 724807 T3102 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38275_solr
[junit4] 2> 724807 T3102 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 724810 T3102 oasc.Overseer.start Overseer (id=91259570090410002-127.0.0.1:38275_solr-n_0000000005) starting
[junit4] 2> 724818 T3146 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 724822 T3146 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 724824 T3145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724825 T3145 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 724826 T3145 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> 724826 T3145 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724827 T3140 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> 724828 T3142 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> 724833 T3145 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> 724833 T3145 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724834 T3140 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> 724834 T3142 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> 724840 T3140 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> 724840 T3142 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> 724845 T3145 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> 724846 T3145 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 724847 T3140 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> 724847 T3142 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> 724851 T3145 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 724888 T3137 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer main queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:411)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:195)
[junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4] 2>
[junit4] 2> 724914 T3116 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[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> 724915 T3116 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:257)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
[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:254)
[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> 724994 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 724998 T3144 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 724999 T3090 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 725002 T3145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 725004 T3145 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> 725004 T3145 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 725009 T3144 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 725011 T3140 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> 725012 T3142 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> 725017 T3142 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 725018 T3140 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 725021 T3090 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 725022 T3142 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 725030 T3144 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 725032 T3145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 725036 T3144 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 725144 T3142 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> 725224
[...truncated too long message...]
=America/Rainy_River
[junit4] 2> NOTE: Linux 3.8.0-35-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=3,free=359876840,total=530186240
[junit4] 2> NOTE: All tests run in this JVM: [TestQuerySenderNoQuery, TestUtils, SolrIndexConfigTest, TestCollapseQParserPlugin, SortByFunctionTest, TestCollationFieldDocValues, CollectionsAPIDistributedZkTest, DirectSolrConnectionTest, ZkNodePropsTest, TestImplicitCoreProperties, HighlighterConfigTest, CurrencyFieldXmlFileTest, DirectUpdateHandlerTest, TestReload, TestJmxIntegration, DirectSolrSpellCheckerTest, OpenCloseCoreStressTest, TestFreeTextSuggestions, TestMaxScoreQueryParser, JSONWriterTest, NoCacheHeaderTest, HighlighterTest, TestInfoStreamLogging, TestBinaryResponseWriter, BasicDistributedZk2Test, TestClassNameShortening, StatsComponentTest, TestAtomicUpdateErrorCases, TestFuzzyAnalyzedSuggestions, TimeZoneUtilsTest, TestQuerySenderListener, TestAddFieldRealTimeGet, PluginInfoTest, TestUpdate, TestCSVLoader, TestIBSimilarityFactory, TestSchemaSimilarityResource, TestDistributedMissingSort, CurrencyFieldOpenExchangeTest, TestIndexSearcher, LeaderElectionIntegrationTest, SolrRequestParserTest, PrimUtilsTest, TermVectorComponentDistributedTest, TestArbitraryIndexDir, TestSolrXml, TestNumberUtils, BadCopyFieldTest, TestComponentsName, TestCopyFieldCollectionResource, HardAutoCommitTest, XsltUpdateRequestHandlerTest, ChaosMonkeySafeLeaderTest, TestFieldTypeResource, TestCollationField, PathHierarchyTokenizerFactoryTest, TestRandomMergePolicy, HdfsSyncSliceTest, BadIndexSchemaTest, TestFoldingMultitermQuery, UniqFieldsUpdateProcessorFactoryTest, DistributedSuggestComponentTest, DebugComponentTest, TestPhraseSuggestions, HdfsUnloadDistributedZkTest, TestSimpleQParserPlugin, SignatureUpdateProcessorFactoryTest, TestStressReorder, TestFastWriter, OutputWriterTest, BasicZkTest, ChaosMonkeyNothingIsSafeTest, TestSolrCoreProperties, DocumentAnalysisRequestHandlerTest, XmlUpdateRequestHandlerTest, TestHashPartitioner, TestSolrQueryParserDefaultOperatorResource, TestCoreDiscovery, TestPartialUpdateDeduplication, TestSchemaResource, PreAnalyzedUpdateProcessorTest, ZkSolrClientTest, StressHdfsTest, MultiTermTest, RequiredFieldsTest, TestReloadAndDeleteDocs, FieldAnalysisRequestHandlerTest, TestCSVResponseWriter, TestRandomFaceting, ZkCLITest, ShardRoutingCustomTest, TestDistributedSearch, AutoCommitTest, TestDistributedGrouping, DistributedSpellCheckComponentTest, TestRealTimeGet, TestMultiCoreConfBootstrap, TestStressVersions, TestRangeQuery, TestSolr4Spatial, SpellCheckComponentTest, QueryElevationComponentTest, TestFiltering, ShowFileRequestHandlerTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SuggesterFSTTest, DocValuesTest, SuggesterTSTTest, TestStressLucene, SuggesterWFSTTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, TestWordDelimiterFilterFactory, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, DistanceFunctionTest, CacheHeaderTest, IndexBasedSpellCheckerTest, LukeRequestHandlerTest, TestOmitPositions, RequestHandlersTest, MoreLikeThisHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, QueryParsingTest, BinaryUpdateRequestHandlerTest, TestLFUCache, AlternateDirectoryTest, CopyFieldTest, TestSolrDeletionPolicy2, SampleTest, TestDocSet, TestBinaryField, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, ExternalFileFieldSortTest, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, SpellPossibilityIteratorTest, TestCodecSupport, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestDefaultSimilarityFactory, TestJmxMonitoredMap, TestFastOutputStream, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, TestFastLRUCache, PreAnalyzedFieldTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, TestSolrJ, TestDocumentBuilder, SliceStateTest, FileUtilsTest, CursorPagingTest, MigrateRouteKeyTest, ShardSplitTest, TestDistribDocBasedVersion]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestDistribDocBasedVersion -Dtests.seed=DFE94DB5638F853B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hu_HU -Dtests.timezone=America/Rainy_River -Dtests.file.encoding=UTF-8
[junit4] ERROR 0.00s J1 | TestDistribDocBasedVersion (suite) <<<
[junit4] > Throwable #1: java.lang.AssertionError: ERROR: SolrIndexSearcher opens=19 closes=17
[junit4] > at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)
[junit4] > at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:387)
[junit4] > at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:155)
[junit4] > at java.lang.Thread.run(Thread.java:662)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.TestDistribDocBasedVersion:
[junit4] > 1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > 2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
[junit4] > 1) Thread[id=4901, name=searcherExecutor-3045-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > 2) Thread[id=4920, name=searcherExecutor-3053-thread-1, state=WAITING, group=TGRP-TestDistribDocBasedVersion]
[junit4] > at sun.misc.Unsafe.park(Native Method)
[junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] > at __randomizedtesting.SeedInfo.seed([DFE94DB5638F853B]:0)
[junit4] Completed on J1 in 163.43s, 1 test, 1 failure, 2 errors <<< FAILURES!
[...truncated 110 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1308: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:941: There were test failures: 362 suites, 1563 tests, 3 suite-level errors, 1 error, 171 ignored (7 assumptions)
Total time: 51 minutes 53 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