You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/04/02 08:31:24 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 9859
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/9859/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([9FADD11062A45540:9BA55EE37001BA61]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:135)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:156)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:289)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:156)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:667)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:94)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:619)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:853)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:122)
... 46 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:127)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 47 more
Build Log:
[...truncated 11315 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-OverseerTest-1396419750262
[junit4] 2> 1000122 T3577 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
[junit4] 2> 1000123 T3577 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1000123 T3577 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1000126 T3577 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1000127 T3577 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1000127 T3578 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1000227 T3577 oasc.ZkTestServer.run start zk server on port:55780
[junit4] 2> 1000228 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001701 T3581 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1471ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
[junit4] 2> 1001703 T3584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9db1e6b7 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001703 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001705 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001707 T3586 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@978e13df name:ZooKeeperConnection Watcher:127.0.0.1:55780 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001708 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001711 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001713 T3588 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e579b9d3 name:ZooKeeperConnection Watcher:127.0.0.1:55780 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001714 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001715 T3577 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1001719 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1001724 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001724 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001730 T3591 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b0461fa9 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001731 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001731 T3593 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f99001a9 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001732 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001732 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1001734 T3577 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1001736 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1001738 T3577 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1001741 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1001741 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1001741 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1001745 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1001745 T3589 oasc.Overseer.start Overseer (id=91515764753694723-127.0.0.1:55780_solr-n_0000000000) starting
[junit4] 2> 1001749 T3589 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1001749 T3593 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1001750 T3577 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1001753 T3589 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1001760 T3589 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1001765 T3589 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1001769 T3589 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1001774 T3589 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1001783 T3595 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1001783 T3589 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1001784 T3595 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1001784 T3594 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1001785 T3594 oasc.Overseer$ClusterStateUpdater.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.amILeader(Overseer.java:526)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:204)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 1001785 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1001786 T3594 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=91515764753694723-127.0.0.1:55780_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1001787 T3597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d2c18d5f name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1001788 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1001788 T3595 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer java.lang.InterruptedException
[junit4] 2> at java.lang.Thread.sleep(Native Method)
[junit4] 2> at java.lang.Thread.sleep(Thread.java:977)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:119)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:87)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:298)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:212)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 1001791 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1001792 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1001795 T3589 oasc.Overseer.start Overseer (id=91515764753694725-127.0.0.1:55780_solr-n_0000000001) starting
[junit4] 2> 1001809 T3599 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1001810 T3599 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1001810 T3598 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1001813 T3598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1001814 T3598 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> 1001814 T3598 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1001815 T3598 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1001818 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1001819 T3593 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> 1002256 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1002271 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1002279 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002281 T3598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1002281 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002281 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1002285 T3598 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> 1002286 T3598 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1002289 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002289 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1002291 T3601 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fb1b004d name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1002291 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1002293 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1002297 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1002301 T3601 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1002301 T3593 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1002304 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002304 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1002306 T3598 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> 1002307 T3598 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1002310 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002312 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1002412 T3601 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> 1002413 T3593 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> 1002515 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1002520 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002520 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002521 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002523 T3598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1002524 T3598 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> 1002524 T3598 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1002525 T3598 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1002528 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1002631 T3593 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> 1002631 T3601 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> 1003020 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003030 T3601 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003030 T3593 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003031 T3593 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1003031 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003032 T3601 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1003032 T3593 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1003043 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003043 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003044 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003046 T3598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003049 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003152 T3601 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> 1003235 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003237 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003239 T3603 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61eb95b5 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003240 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003242 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1003247 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1003250 T3601 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003250 T3603 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003253 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003253 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003253 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003254 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003255 T3598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003256 T3598 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> 1003256 T3598 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003260 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003262 T3603 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003262 T3601 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003263 T3603 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1003266 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003266 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003267 T3598 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> 1003268 T3598 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003272 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003277 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003277 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003279 T3605 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2efc56c7 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003279 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003281 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1003285 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1003288 T3603 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003288 T3605 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003290 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003290 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003292 T3598 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> 1003292 T3598 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003296 T3597 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003298 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003311 T3589 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1003314 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003316 T3607 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a06ede86 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003316 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003321 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1003321 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1003324 T3589 oasc.Overseer.start Overseer (id=91515764753694729-127.0.0.1:55780_solr-n_0000000002) starting
[junit4] 2> 1003339 T3609 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1003340 T3609 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1003341 T3608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003342 T3608 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1003343 T3608 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> 1003343 T3608 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003344 T3603 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> 1003344 T3605 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> 1003348 T3608 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> 1003348 T3608 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003349 T3605 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> 1003349 T3603 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> 1003354 T3605 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> 1003354 T3603 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> 1003357 T3608 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> 1003358 T3608 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003359 T3603 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> 1003359 T3605 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> 1003361 T3608 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1003500 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003506 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003506 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003508 T3608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003509 T3608 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> 1003510 T3608 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003513 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003514 T3605 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> 1003514 T3603 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> 1003516 T3605 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003517 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003518 T3605 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1003523 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003525 T3608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003528 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003631 T3605 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> 1003719 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003721 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003724 T3611 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c29b0f5 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003725 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003727 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1003730 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1003733 T3605 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003733 T3611 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003736 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003736 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003738 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003738 T3607 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003739 T3589 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1003739 T3608 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003741 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003743 T3613 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@858a5f97 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003743 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003747 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1003748 T3611 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003748 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1003748 T3605 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1003750 T3611 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1003751 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003752 T3589 oasc.Overseer.start Overseer (id=91515764753694731-127.0.0.1:55780_solr-n_0000000003) starting
[junit4] 2> 1003759 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1003761 T3615 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8b26ffda name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1003761 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1003763 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1003767 T3617 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1003767 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1003768 T3616 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1003767 T3617 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1003772 T3611 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003773 T3615 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1003774 T3616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003775 T3616 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> 1003775 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003775 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003776 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003782 T3615 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> 1003782 T3611 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> 1003785 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003786 T3616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003787 T3616 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> 1003788 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003791 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003795 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003796 T3616 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> 1003797 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1003800 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003903 T3615 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> 1003903 T3611 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> 1003987 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003992 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003993 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003993 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1003994 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1003995 T3616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1003996 T3616 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> 1003997 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004000 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004002 T3611 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004002 T3615 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004005 T3615 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1004009 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004010 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004013 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004115 T3615 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> 1004213 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004215 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004217 T3619 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6af1641d name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004218 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004220 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1004224 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1004227 T3615 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004227 T3619 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004230 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004230 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004230 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004232 T3616 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004232 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004233 T3616 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> 1004233 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004239 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004241 T3619 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004242 T3615 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004244 T3619 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1004245 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004245 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004246 T3616 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> 1004247 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004249 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004253 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004253 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004255 T3621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a7107385 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004255 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004257 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1004260 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1004262 T3619 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004263 T3621 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004265 T3613 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004265 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004266 T3616 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> 1004266 T3616 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004267 T3589 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1004269 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004271 T3623 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f3bbe468 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004272 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004274 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004275 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1004276 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1004278 T3589 oasc.Overseer.start Overseer (id=91515764753694735-127.0.0.1:55780_solr-n_0000000004) starting
[junit4] 2> 1004293 T3625 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1004294 T3625 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1004295 T3624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004296 T3624 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1004297 T3624 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> 1004297 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004298 T3621 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> 1004298 T3619 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> 1004302 T3624 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> 1004303 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004304 T3619 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> 1004304 T3621 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> 1004308 T3621 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> 1004308 T3619 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> 1004312 T3624 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> 1004312 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004313 T3619 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> 1004313 T3621 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> 1004315 T3624 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1004318 T3624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004319 T3624 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> 1004320 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004323 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004324 T3621 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> 1004324 T3619 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> 1004477 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004482 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004482 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004484 T3624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004485 T3624 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> 1004486 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004489 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004490 T3621 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004490 T3619 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004492 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004492 T3619 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1004493 T3621 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1004494 T3619 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1004499 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004502 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004605 T3621 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> 1004694 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004695 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004696 T3627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76df name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004697 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004698 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1004699 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1004701 T3627 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004701 T3621 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004702 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004702 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004702 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004703 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004703 T3624 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004703 T3624 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> 1004704 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004706 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004706 T3627 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004706 T3621 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004707 T3627 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1004708 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004708 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004708 T3624 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> 1004709 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004710 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004712 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004713 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004714 T3629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dfb548a name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004714 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004715 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1004716 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1004718 T3627 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004718 T3629 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1004720 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004720 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004720 T3624 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> 1004721 T3624 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004722 T3623 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004723 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004794 T3589 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1004796 T3589 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1004798 T3631 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e0e5141 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1004799 T3589 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1004803 T3589 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:55780_solr
[junit4] 2> 1004804 T3589 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1004806 T3589 oasc.Overseer.start Overseer (id=91515764753694738-127.0.0.1:55780_solr-n_0000000005) starting
[junit4] 2> 1004826 T3633 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1004827 T3633 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1004828 T3632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004829 T3632 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1004830 T3632 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> 1004830 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004831 T3629 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> 1004831 T3627 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> 1004835 T3632 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> 1004836 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004837 T3627 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> 1004837 T3629 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> 1004842 T3627 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> 1004843 T3629 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> 1004846 T3632 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> 1004847 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004848 T3627 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> 1004848 T3629 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> 1004850 T3632 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1004925 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004930 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004930 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1004932 T3632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004933 T3632 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> 1004933 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1004937 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004938 T3629 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> 1004938 T3627 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> 1004940 T3629 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1004940 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004942 T3629 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1004950 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1004952 T3632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1004956 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005015 T3603 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1005016 T3603 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1005016 T3603 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1005017 T3603 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:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java: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:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 1005059 T3629 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> 1005143 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1005146 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1005148 T3635 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@909dd386 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1005148 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1005150 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1005154 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1005158 T3629 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1005158 T3635 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1005161 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005161 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1005161 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005163 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005164 T3632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1005165 T3632 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> 1005166 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1005169 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005170 T3635 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1005170 T3629 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1005172 T3635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1005173 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005173 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1005174 T3632 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> 1005175 T3632 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1005180 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005184 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005185 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1005186 T3637 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6769c6a7 name:ZooKeeperConnection Watcher:127.0.0.1:55780/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1005187 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1005189 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1005192 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1005196 T3637 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1005196 T3635 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1005199 T3631 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1005199 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1005201 T3632 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> 1005202 T3632 oasc.Overseer$ClusterStateUpdater.
[...truncated too long message...]
ng... (live nodes size: 1)
[junit4] 2> 1048429 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1048441 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1048450 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048450 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1048452 T4031 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1048453 T4022 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1048453 T4028 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1048455 T3577 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1048455 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048457 T4034 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c565dd7 name:ZooKeeperConnection Watcher:127.0.0.1:49402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1048457 T3577 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1048459 T3577 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1048462 T3577 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1048465 T4022 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1048465 T4034 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1048468 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048468 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1048469 T4031 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "node_name":"node1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "base_url":"http://node1/solr/"}
[junit4] 2> 1048470 T4031 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1048473 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048475 T3577 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1048480 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048484 T4030 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1048587 T4022 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> 1048587 T4034 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> 1048588 T3577 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1048592 T4022 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1048592 T4034 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1048594 T3577 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49402 49402
[junit4] 2> 1050090 T4031 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-work/qn-0000000002
[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.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.remove(DistributedQueue.java:179)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.poll(DistributedQueue.java:493)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:265)
[junit4] 2> at java.lang.Thread.run(Thread.java:853)
[junit4] 2>
[junit4] 2> 1053774 T4016 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49402 49402
[junit4] 2> 1053775 T3577 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1053780 T3577 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1053781 T3577 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1056782 T3577 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_JO, timezone=Africa/Freetown
[junit4] 2> NOTE: Linux 3.8.0-37-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=44493440,total=240779264
[junit4] 2> NOTE: All tests run in this JVM: [CursorPagingTest, NumericFieldsTest, SolrRequestParserTest, TestCollationFieldDocValues, TestRecovery, BasicZkTest, TestCSVResponseWriter, OpenCloseCoreStressTest, SolrPluginUtilsTest, SSLMigrationTest, CustomCollectionTest, TestAnalyzedSuggestions, MigrateRouteKeyTest, TestBinaryField, TestFastLRUCache, CurrencyFieldXmlFileTest, TestSolrDeletionPolicy2, TestCSVLoader, TestIndexSearcher, TestSolrQueryParserDefaultOperatorResource, TestArbitraryIndexDir, ZkNodePropsTest, TestStressRecovery, OutputWriterTest, ChaosMonkeyNothingIsSafeTest, MinimalSchemaTest, TestDistribDocBasedVersion, DeleteInactiveReplicaTest, TestZkChroot, TestCloudManagedSchemaAddField, DefaultValueUpdateProcessorTest, DistributedExpandComponentTest, TermVectorComponentDistributedTest, TestSweetSpotSimilarityFactory, TestMiniSolrCloudCluster, TestSchemaNameResource, TestIBSimilarityFactory, PluginInfoTest, UniqFieldsUpdateProcessorFactoryTest, TestQueryTypes, TestUniqueKeyFieldResource, ConvertedLegacyTest, TestCollationField, BadIndexSchemaTest, SpellingQueryConverterTest, TestUtils, TestSolrXml, AddBlockUpdateTest, RequestHandlersTest, ConnectionManagerTest, SignatureUpdateProcessorFactoryTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestMultiCoreConfBootstrap, TestRandomFaceting, PreAnalyzedUpdateProcessorTest, TestInitQParser, HdfsBasicDistributedZkTest, DisMaxRequestHandlerTest, TestUpdate, TestSolrCoreProperties, DirectUpdateHandlerTest, TestStressLucene, TestSimpleQParserPlugin, TestHashPartitioner, BasicDistributedZk2Test, TestDistributedGrouping, TestFastOutputStream, TestFastWriter, OpenExchangeRatesOrgProviderTest, ShardRoutingCustomTest, SolrIndexConfigTest, PreAnalyzedFieldTest, TestJmxIntegration, IndexBasedSpellCheckerTest, SolrTestCaseJ4Test, SpellCheckComponentTest, DistributedQueryComponentCustomSortTest, TestSchemaSimilarityResource, TestStandardQParsers, DebugComponentTest, InfoHandlerTest, TestDocBasedVersionConstraints, HardAutoCommitTest, SolrXmlInZkTest, JSONWriterTest, NoCacheHeaderTest, CoreAdminCreateDiscoverTest, TestFieldTypeResource, ChaosMonkeySafeLeaderTest, TestOmitPositions, TestBinaryResponseWriter, SortByFunctionTest, DocumentAnalysisRequestHandlerTest, CollectionsAPIDistributedZkTest, OverseerTest]
[junit4] Completed on J1 in 56.70s, 9 tests, 1 error <<< FAILURES!
[...truncated 593 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:460: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1276: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:908: There were test failures: 382 suites, 1611 tests, 1 error, 45 ignored (16 assumptions)
Total time: 65 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure