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/01/03 20:54:01 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 1158 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1158/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
Stack Trace:
org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at __randomizedtesting.SeedInfo.seed([83704928BA4AC479:8778C6DBA8EF2B58]:0)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:428)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:425)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:157)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:153)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:584)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10363 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> 1139595 T4236 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-OverseerTest-1388776639111
[junit4] 2> 1139596 T4236 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1139601 T4236 oas.SolrTestCaseJ4.setUp ###Starting testDoubleAssignment
[junit4] 2> 1139601 T4236 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1139602 T4237 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1139703 T4236 oasc.ZkTestServer.run start zk server on port:57573
[junit4] 2> 1139705 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1139713 T4244 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@196504a0 name:ZooKeeperConnection Watcher:127.0.0.1:57573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1139713 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1139715 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1139720 T4247 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e36e668 name:ZooKeeperConnection Watcher:127.0.0.1:57573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1139720 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1139727 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1139733 T4250 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49ece768 name:ZooKeeperConnection Watcher:127.0.0.1:57573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1139734 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1139734 T4236 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1139746 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1139758 T4236 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1139770 T4236 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1139779 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1139797 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1139805 T4253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c93af55 name:ZooKeeperConnection Watcher:127.0.0.1:57573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1139806 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1139812 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1139826 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1139842 T4244 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1139843 T4253 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1139844 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1139852 T4256 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c039371 name:ZooKeeperConnection Watcher:127.0.0.1:57573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1139853 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1139857 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1139871 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1139895 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1139909 T4236 oasc.Overseer.start Overseer (id=91014865821433860-127.0.0.1:57573_solr-n_0000000000) starting
[junit4] 2> 1139921 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1139942 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1139959 T4236 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1139975 T4258 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1139983 T4257 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1139998 T4257 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1140001 T4257 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> 1140002 T4257 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1140002 T4257 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1140018 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140023 T4253 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> 1140023 T4244 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> 1140489 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1140545 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1140580 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140582 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1140587 T4257 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1140596 T4253 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1140598 T4244 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1140604 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1140606 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140610 T4261 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a91033e name:ZooKeeperConnection Watcher:127.0.0.1:57573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1140611 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1140614 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1140624 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1140636 T4244 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1140637 T4261 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1140646 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1140646 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140651 T4257 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> 1140652 T4257 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1140662 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140670 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1140688 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140697 T4256 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1140802 T4244 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> 1140803 T4261 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> 1140807 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1140815 T4244 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1140816 T4261 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1140819 T4238 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1435989ca910000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1141021 T4236 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57573 57573
[junit4] 2> 1141041 T4236 oas.SolrTestCaseJ4.tearDown ###Ending testDoubleAssignment
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1141051 T4236 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 1141052 T4236 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1141053 T4262 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1141158 T4236 oasc.ZkTestServer.run start zk server on port:57580
[junit4] 2> 1141161 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141174 T4269 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a3cff58 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141175 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141180 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141190 T4272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@160acbcc name:ZooKeeperConnection Watcher:127.0.0.1:57580 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141190 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141333 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141341 T4275 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10d05710 name:ZooKeeperConnection Watcher:127.0.0.1:57580 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141342 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141342 T4236 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1141356 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1141372 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141374 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141383 T4280 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4137eaae name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141384 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141384 T4282 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26d77ea8 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141387 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141388 T4236 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1141390 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1141401 T4236 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1141403 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1141408 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1141415 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1141416 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1141421 T4280 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1141423 T4276 oasc.Overseer.start Overseer (id=91014865916854276-127.0.0.1:57580_solr-n_0000000000) starting
[junit4] 2> 1141426 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1141428 T4276 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1141438 T4276 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1141451 T4276 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1141461 T4276 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1141461 T4284 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1141466 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1141470 T4287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61f02ffc name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1141471 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1141480 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1141487 T4276 oasc.Overseer.start Overseer (id=91014865916854277-127.0.0.1:57580_solr-n_0000000001) starting
[junit4] 2> 1141501 T4289 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1141504 T4288 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1141510 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1141512 T4288 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> 1141513 T4288 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 1141513 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1141523 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1141524 T4280 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> 1141937 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1141996 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1142036 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142048 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142049 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1142048 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142072 T4288 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> 1142072 T4288 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1142075 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1142078 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142080 T4292 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@315e9a87 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1142080 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1142086 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1142094 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1142102 T4280 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1142102 T4292 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1142106 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142107 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1142110 T4288 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> 1142110 T4288 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1142117 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142123 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142230 T4280 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> 1142231 T4292 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> 1142330 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142345 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142345 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142346 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142355 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142358 T4288 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> 1142358 T4288 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 1142358 T4288 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1142372 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142484 T4292 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> 1142486 T4280 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> 1142849 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1142893 T4280 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1142896 T4292 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1142901 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142906 T4292 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1142924 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142924 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142924 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142929 T4288 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1142944 T4287 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1142963 T4284 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:156)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1142967 T4284 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91014865916854276-127.0.0.1:57580_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1142967 T4284 oasc.OverseerCollectionProcessor.amILeader org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1151)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:273)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:270)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.amILeader(OverseerCollectionProcessor.java:204)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:163)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1142968 T4284 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91014865916854276-127.0.0.1:57580_solr-n_0000000000) am no longer a leader.
[junit4] 2> 1142965 T4283 oasc.Overseer$ClusterStateUpdater.run WARN Solr cannot talk to ZK, exiting Overseer work queue loop org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue-work
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.orderedChildren(DistributedQueue.java:89)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.element(DistributedQueue.java:131)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.peek(DistributedQueue.java:325)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:105)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1143057 T4292 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> 1143111 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143119 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143123 T4276 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1143129 T4295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29be6d2d name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143131 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143135 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143140 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1143148 T4298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ad4116c name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143149 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143155 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1143159 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1143164 T4295 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143165 T4292 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143169 T4276 oasc.Overseer.start Overseer (id=91014865916854280-127.0.0.1:57580_solr-n_0000000002) starting
[junit4] 2> 1143171 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143181 T4300 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1143183 T4299 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1143188 T4299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143189 T4295 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1143191 T4299 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> 1143191 T4299 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143193 T4295 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1143194 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143195 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143207 T4295 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> 1143210 T4299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143212 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143212 T4299 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> 1143213 T4299 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143216 T4303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@112ecdfe name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143217 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143220 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143220 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1143226 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1143227 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143232 T4295 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143233 T4303 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143238 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143238 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143240 T4299 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> 1143241 T4299 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143247 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143253 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143361 T4303 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> 1143361 T4295 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> 1143462 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143477 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143478 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143479 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143477 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143486 T4299 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143489 T4299 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> 1143489 T4299 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143504 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143519 T4295 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1143521 T4303 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1143529 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143529 T4303 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1143542 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143553 T4298 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143663 T4303 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> 1143735 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143742 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143748 T4306 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f4b6e8a name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143749 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143756 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1143772 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1143787 T4303 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143788 T4306 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143791 T4276 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1143797 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143799 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143808 T4309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20ef2e43 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143808 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143817 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1143823 T4276 oasc.Overseer.start Overseer (id=91014865916854283-127.0.0.1:57580_solr-n_0000000003) starting
[junit4] 2> 1143823 T4306 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1143823 T4303 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1143829 T4306 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1143831 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143837 T4311 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1143840 T4310 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1143845 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143847 T4310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143848 T4310 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> 1143849 T4310 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143850 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1143854 T4314 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@794937e name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1143854 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1143858 T4306 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> 1143858 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1143865 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1143867 T4310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143870 T4310 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> 1143871 T4310 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143872 T4306 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143872 T4314 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1143877 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143877 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1143886 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1143889 T4310 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> 1143889 T4310 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1143891 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1143894 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144006 T4306 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> 1144006 T4314 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> 1144102 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144116 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1144117 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144118 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144118 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144129 T4310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144132 T4310 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> 1144133 T4310 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144147 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144153 T4306 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144153 T4314 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144154 T4306 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1144156 T4306 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1144156 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144157 T4314 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1144174 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144184 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144294 T4314 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> 1144365 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144372 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1144382 T4317 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@293b2ccd name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1144383 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1144390 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1144400 T4280 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1144402 T4280 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1144406 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1144423 T4314 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1144423 T4317 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1144434 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144434 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144435 T4309 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144434 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1144444 T4310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144447 T4276 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1144447 T4310 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> 1144448 T4310 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144455 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1144463 T4320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d6b4812 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1144465 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1144471 T4317 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144472 T4314 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144476 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1144477 T4317 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1144480 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1144482 T4276 oasc.Overseer.start Overseer (id=91014865916854286-127.0.0.1:57580_solr-n_0000000004) starting
[junit4] 2> 1144496 T4322 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1144498 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1144498 T4321 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1144503 T4325 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11e77303 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1144503 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1144505 T4321 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144506 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1144507 T4321 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> 1144507 T4321 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144512 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1144513 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144516 T4317 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> 1144516 T4325 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> 1144521 T4325 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1144521 T4317 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1144525 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1144528 T4321 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144530 T4321 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> 1144530 T4321 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144536 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144538 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144544 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144547 T4321 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> 1144547 T4321 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144553 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144666 T4317 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> 1144667 T4325 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> 1144688 T4292 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1144747 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144762 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1144762 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144763 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144764 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144771 T4321 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144774 T4321 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> 1144775 T4321 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1144790 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144798 T4317 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144799 T4325 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1144802 T4263 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1435989d041000d, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1144807 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1144807 T4325 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1144837 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144855 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1144967 T4325 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> 1145015 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145022 T4295 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1145023 T4295 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:253)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1145025 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1145031 T4328 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@491c5195 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1145032 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1145038 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1145053 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 1145068 T4328 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1145068 T4325 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1145079 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145080 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145080 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145079 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1145088 T4321 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145091 T4321 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> 1145092 T4321 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1145105 T4276 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 1145108 T4320 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145110 T4276 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1145115 T4331 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@566cacf4 name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1145115 T4276 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1145117 T4325 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1145117 T4328 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1145121 T4328 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1145124 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1145126 T4276 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1145134 T4276 oasc.Overseer.start Overseer (id=91014865916854289-127.0.0.1:57580_solr-n_0000000005) starting
[junit4] 2> 1145141 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1145146 T4334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9546ccb name:ZooKeeperConnection Watcher:127.0.0.1:57580/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1145146 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1145147 T4336 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1145149 T4236 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1145152 T4335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145154 T4335 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1145155 T4335 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> 1145155 T4335 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1145156 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes/node2
[junit4] 2> 1145158 T4334 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> 1145158 T4328 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> 1145164 T4334 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1145164 T4335 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1145164 T4328 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1145169 T4335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145170 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1145169 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145171 T4335 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> 1145171 T4335 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1145179 T4334 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> 1145179 T4328 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> 1145189 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145195 T4335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145206 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145209 T4335 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> 1145210 T4335 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1145218 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145328 T4328 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> 1145328 T4334 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> 1145397 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145412 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145413 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145413 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145412 T4236 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1145421 T4335 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145424 T4335 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> 1145424 T4335 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 1145441 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145451 T4328 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1145451 T4334 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1145456 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145461 T4334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1145490 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145509 T4331 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1145621 T4334 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> 1145665 T4236 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1145774 T4334 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1145950 T4310 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-
[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.create(ZooKeeper.java:783)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:239)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:236)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.create(SolrZkClient.java:236)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.createData(DistributedQueue.java:284)
[junit4] 2> at org.apache.solr.cloud.DistributedQueue.offer(DistributedQueue.java:271)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:188)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1145951 T4236 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57580 57580
[junit4] 2> 1145990 T4236 oas.SolrTestCaseJ4.tearDown ###Ending testShardLeaderChange
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1146012 T4236 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 1146012 T4236 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1146014 T4337 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1146118 T4236 oasc.ZkTestServer.run start zk server on port:57600
[junit4] 2> 1146121 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1146134 T4344 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f5bef7d name:ZooKeeperConnection Watcher:127.0.0.1:57600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1146135 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1146205 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1146208 T4347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@729bfaa0 name:ZooKeeperConnection Watcher:127.0.0.1:57600 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1146209 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1146209 T4236 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1146217 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1146221 T4350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@159082b3 name:ZooKeeperConnection Watcher:127.0.0.1:57600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1146221 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1146222 T4236 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1146227 T4236 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1146231 T4353 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d6021f7 name:ZooKeeperConnection Watcher:127.0.0.1:57600/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1146231 T4236 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1146233 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1146239 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1146251 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1146258 T4236 oasc.Overseer.start Overseer (id=91014866244075523-127.0.0.1:57600_solr-n_0000000000) starting
[junit4] 2> 1146265 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1146276 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1146286 T4236 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1146292 T4355 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1146294 T4236 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1146295 T4354 oasc
[...truncated too long message...]
[junit4] 2> 1171222 T4236 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1171228 T4236 oasc.Overseer.start Overseer (id=91014867877232643-127.0.0.1:57706_solr-n_0000000000) starting
[junit4] 2> 1171234 T4236 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1171246 T4236 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1171253 T4772 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1171260 T4771 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1171262 T4771 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 1171263 T4771 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1171266 T4761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1171273 T4771 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core2",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1171275 T4761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1171280 T4771 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1171285 T4771 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1171287 T4771 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "shard":"s1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core3",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 1171293 T4770 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1171295 T4761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 0)
[junit4] 2> 1171511 T4236 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57706 57706
[junit4] 2> 1171615 T4236 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 1171618 T4236 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 1171619 T4236 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 1172279 T4743 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1172279 T4743 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:205)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:202)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:413)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:382)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:369)
[junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:112)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
[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:138)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4] 2>
[junit4] 2> 1172280 T4743 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1174620 T4236 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=es, timezone=Etc/GMT+4
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=119910840,total=313405440
[junit4] 2> NOTE: All tests run in this JVM: [TestShardHandlerFactory, TestDocumentBuilder, SolrCmdDistributorTest, ZkControllerTest, SolrInfoMBeanTest, TestZkChroot, SignatureUpdateProcessorFactoryTest, ShardRoutingTest, SolrRequestParserTest, OutputWriterTest, TestCSVLoader, TestXIncludeConfig, TestSystemIdResolver, QueryElevationComponentTest, TestSurroundQueryParser, BasicDistributedZkTest, InfoHandlerTest, SimplePostToolTest, DocValuesTest, CacheHeaderTest, TestRealTimeGet, HdfsDirectoryTest, BinaryUpdateRequestHandlerTest, DirectSolrConnectionTest, SoftAutoCommitTest, SolrXmlInZkTest, TestPerFieldSimilarity, TestSolr4Spatial, IndexSchemaRuntimeFieldTest, XmlUpdateRequestHandlerTest, DirectUpdateHandlerTest, DocumentAnalysisRequestHandlerTest, DisMaxRequestHandlerTest, TestAtomicUpdateErrorCases, BadIndexSchemaTest, PluginInfoTest, TestCodecSupport, DistributedDebugComponentTest, CoreAdminCreateDiscoverTest, DirectUpdateHandlerOptimizeTest, TestJmxMonitoredMap, FileBasedSpellCheckerTest, TestFastLRUCache, DocValuesMissingTest, FieldAnalysisRequestHandlerTest, RecoveryZkTest, TestSimpleQParserPlugin, RAMDirectoryFactoryTest, HdfsBasicDistributedZkTest, TestRandomDVFaceting, HdfsBasicDistributedZk2Test, TermsComponentTest, DOMUtilTest, JsonLoaderTest, TestStressUserVersions, DebugComponentTest, TestCustomSort, TestBadConfig, TestArbitraryIndexDir, SuggesterTest, SpatialFilterTest, TestCoreDiscovery, CSVRequestHandlerTest, TestBinaryField, OpenCloseCoreStressTest, SolrIndexConfigTest, TestFoldingMultitermQuery, ZkNodePropsTest, TestFastOutputStream, ChaosMonkeyNothingIsSafeTest, DistributedQueryElevationComponentTest, TestExtendedDismaxParser, FastVectorHighlighterTest, PathHierarchyTokenizerFactoryTest, DistanceFunctionTest, TestImplicitCoreProperties, BJQParserTest, TestFiltering, DocumentBuilderTest, StandardRequestHandlerTest, ChangedSchemaMergeTest, TestLMJelinekMercerSimilarityFactory, TestWriterPerf, SliceStateUpdateTest, TestCharFilters, OverseerCollectionProcessorTest, TestFieldTypeCollectionResource, TestBinaryResponseWriter, ZkCLITest, TestConfig, TestSolrDeletionPolicy2, AddSchemaFieldsUpdateProcessorFactoryTest, StressHdfsTest, DefaultValueUpdateProcessorTest, MigrateRouteKeyTest, TestOmitPositions, LeaderElectionTest, TestDistribDocBasedVersion, SOLR749Test, TestAnalyzeInfixSuggestions, BasicDistributedZk2Test, AliasIntegrationTest, TestInfoStreamLogging, EchoParamsTest, TestCSVResponseWriter, ClusterStateUpdateTest, CoreContainerCoreInitFailuresTest, SystemInfoHandlerTest, ParsingFieldUpdateProcessorsTest, TestFunctionQuery, UpdateRequestProcessorFactoryTest, SpellCheckComponentTest, TestReplicationHandler, TermVectorComponentDistributedTest, HdfsUnloadDistributedZkTest, OverseerTest]
[junit4] Completed in 35.09s, 8 tests, 1 error <<< FAILURES!
[...truncated 703 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:459: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:439: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:491: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1307: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:940: There were test failures: 348 suites, 1522 tests, 1 error, 40 ignored (5 assumptions)
Total time: 89 minutes 0 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure