You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/04/13 19:06:13 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_51) - Build #
3868 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3868/
Java: 32bit/jdk1.7.0_51 -client -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.OverseerTest.testOverseerFailure
Error Message:
Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
Stack Trace:
org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
at __randomizedtesting.SeedInfo.seed([C0C61B515A14DEBF:C4CE94A248B1319E]:0)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 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:65)
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:360)
at java.lang.Thread.run(Thread.java:744)
Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
... 45 more
Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
... 46 more
Build Log:
[...truncated 11224 lines...]
[junit4] Suite: org.apache.solr.cloud.OverseerTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-C0C61B515A14DEBF-001\init-core-data-001
[junit4] 2> 2451561 T6635 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 2451561 T6635 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2451562 T6635 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2451566 T6635 oas.SolrTestCaseJ4.setUp ###Starting testOverseerFailure
[junit4] 2> 2451567 T6635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2451568 T6636 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2451663 T6635 oasc.ZkTestServer.run start zk server on port:62011
[junit4] 2> 2451666 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2451673 T6642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ef37bb name:ZooKeeperConnection Watcher:127.0.0.1:62011 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2451673 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2451678 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2451680 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2451682 T6644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fca1d9 name:ZooKeeperConnection Watcher:127.0.0.1:62011 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2451683 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2451683 T6635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2451691 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2451692 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2451695 T6646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b96a83 name:ZooKeeperConnection Watcher:127.0.0.1:62011/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2451695 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2451695 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2451700 T6635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2451704 T6635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2451707 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2451714 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2451717 T6648 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ec863b name:ZooKeeperConnection Watcher:127.0.0.1:62011/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2451717 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2451719 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2451724 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2451728 T6646 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2451729 T6648 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2451732 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2451735 T6650 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d6bbc name:ZooKeeperConnection Watcher:127.0.0.1:62011/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2451735 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2451736 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2451740 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2451748 T6635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62011_solr
[junit4] 2> 2451749 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2451756 T6635 oasc.Overseer.start Overseer (id=91580448659865604-127.0.0.1:62011_solr-n_0000000000) starting
[junit4] 2> 2451760 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2451765 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2451771 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2451777 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2451782 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2451790 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2451804 T6652 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2451805 T6652 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62011_solr
[junit4] 2> 2451805 T6651 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2452749 T6650 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2452752 T6651 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2452753 T6651 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> 2452754 T6651 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2452754 T6651 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2452762 T6650 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2452764 T6648 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> 2452765 T6646 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> 2453220 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2453241 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2453251 T6650 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2453252 T6635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2453253 T6651 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2453257 T6650 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2453258 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2453262 T6651 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[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> 2453262 T6651 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2453267 T6650 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2453365 T6646 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> 2453366 T6648 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> 2453417 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2454390 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2454402 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2454406 T6654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@88f77 name:ZooKeeperConnection Watcher:127.0.0.1:62011/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2454406 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2454407 T6651 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62011_solr
[junit4] 2> 2454411 T6655 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2454415 T6635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62011_solr
[junit4] 2> 2454416 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2454420 T6635 oasc.Overseer.start Overseer (id=91580448659865605-127.0.0.1:62011_solr-n_0000000001) starting
[junit4] 2> 2454445 T6657 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2454446 T6656 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2454446 T6657 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62011_solr
[junit4] 2> 2454449 T6656 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2454450 T6656 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> 2454450 T6656 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2454455 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454458 T6646 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> 2454458 T6648 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> 2454515 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454516 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2454519 T6656 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2454530 T6648 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2454531 T6656 oasc.SolrException.log ERROR Problem cleaning up collection in zk:collection1:org.apache.zookeeper.KeeperException$NotEmptyException: KeeperErrorCode = Directory not empty for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:125)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:631)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.clean(SolrZkClient.java:626)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.removeCore(Overseer.java:1069)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.processMessage(Overseer.java:342)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:241)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2454531 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2454536 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454543 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454545 T6648 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2454546 T6656 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2454550 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454554 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454556 T6656 oasc.Overseer$ClusterStateUpdater.setShardLeader ERROR Could not mark shard leader for non existing collection:collection1
[junit4] 2> 2454560 T6654 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2454670 T6648 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> 2454671 T6646 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> 2455576 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2456621 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2457663 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2458703 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2459745 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2460786 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2461834 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2462882 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2463929 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2465024 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2466174 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2467325 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2468475 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2469628 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2470778 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2470792 T6648 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2470793 T6646 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2470796 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2470798 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2470803 T6637 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455beecebe0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2470803 T6635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62011 62011
[junit4] 2> 2473369 T6636 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62011 62011
[junit4] 2> 2473375 T6635 oas.SolrTestCaseJ4.tearDown ###Ending testOverseerFailure
[junit4] 2> 2473376 T6656 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62011_solr
[junit4] 2> 2473379 T6658 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OverseerTest -Dtests.method=testOverseerFailure -Dtests.seed=C0C61B515A14DEBF -Dtests.slow=true -Dtests.locale=ar_EG -Dtests.timezone=MST -Dtests.file.encoding=UTF-8
[junit4] ERROR 21.8s | OverseerTest.testOverseerFailure <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not register as the leader because creating the ephemeral registration node in ZooKeeper failed
[junit4] > at __randomizedtesting.SeedInfo.seed([C0C61B515A14DEBF:C4CE94A248B1319E]:0)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:136)
[junit4] > at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
[junit4] > at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
[junit4] > at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:267)
[junit4] > at org.apache.solr.cloud.OverseerTest$MockZKController.publishState(OverseerTest.java:155)
[junit4] > at org.apache.solr.cloud.OverseerTest.testOverseerFailure(OverseerTest.java:661)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] > Caused by: org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:40)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
[junit4] > ... 45 more
[junit4] > Caused by: org.apache.zookeeper.KeeperException$NodeExistsException: KeeperErrorCode = NodeExists for /collections/collection1/leaders/shard1
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:119)
[junit4] > at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] > at org.apache.zookeeper.ZooKeeper.create(ZooKeeper.java:783)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient$10.execute(SolrZkClient.java:432)
[junit4] > at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:429)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
[junit4] > at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
[junit4] > at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
[junit4] > at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:34)
[junit4] > ... 46 more
[junit4] 2> 2473411 T6635 oas.SolrTestCaseJ4.setUp ###Starting testReplay
[junit4] 2> 2473415 T6635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2473416 T6659 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2473529 T6635 oasc.ZkTestServer.run start zk server on port:62032
[junit4] 2> 2473534 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2473544 T6665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bd8735 name:ZooKeeperConnection Watcher:127.0.0.1:62032/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2473544 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2473548 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2473571 T6667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e83107 name:ZooKeeperConnection Watcher:127.0.0.1:62032 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2473573 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2473577 T6660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef241c0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2473578 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2473583 T6669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35ddac name:ZooKeeperConnection Watcher:127.0.0.1:62032 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2473584 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2473585 T6635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2473593 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2473593 T6660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef241c0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2473598 T6635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2473602 T6635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2473605 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2473611 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2473621 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2473623 T6671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19e1dbc name:ZooKeeperConnection Watcher:127.0.0.1:62032/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2473623 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2473624 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2473628 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2473637 T6635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62032_solr
[junit4] 2> 2473637 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2473643 T6635 oasc.Overseer.start Overseer (id=91580450092089347-127.0.0.1:62032_solr-n_0000000000) starting
[junit4] 2> 2473647 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2473658 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2473666 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2473674 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2473684 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2473700 T6673 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2473701 T6673 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62032_solr
[junit4] 2> 2473706 T6672 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2473709 T6672 oasc.Overseer$ClusterStateUpdater.run Replaying operations from work queue.
[junit4] 2> 2473710 T6672 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> 2473712 T6665 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> 2473722 T6672 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> 2473725 T6665 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> 2473732 T6672 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2473740 T6672 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2473741 T6672 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> 2473750 T6671 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2473753 T6665 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> 2473821 T6660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef241c0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2473823 T6635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62032 62032
[junit4] 2> 2473823 T6660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef241c0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2476450 T6659 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62032 62032
[junit4] 2> 2476455 T6635 oas.SolrTestCaseJ4.tearDown ###Ending testReplay
[junit4] 2> 2476459 T6672 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62032_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2476462 T6674 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2476477 T6635 oas.SolrTestCaseJ4.setUp ###Starting testStateChange
[junit4] 2> 2476481 T6635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2476482 T6675 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2476608 T6635 oasc.ZkTestServer.run start zk server on port:62047
[junit4] 2> 2476612 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2476618 T6681 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c09e53 name:ZooKeeperConnection Watcher:127.0.0.1:62047/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2476619 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2476620 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2476624 T6683 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10a3f29 name:ZooKeeperConnection Watcher:127.0.0.1:62047 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2476624 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2476627 T6676 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef30160001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2476629 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2476631 T6685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1561df4 name:ZooKeeperConnection Watcher:127.0.0.1:62047 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2476632 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2476632 T6635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2476638 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2476638 T6676 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef30160002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2476643 T6635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2476648 T6635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2476652 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2476658 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2476661 T6687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@128f543 name:ZooKeeperConnection Watcher:127.0.0.1:62047/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2476661 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2476662 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2476667 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2476674 T6635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62047_solr
[junit4] 2> 2476674 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2476678 T6635 oasc.Overseer.start Overseer (id=91580450293022723-127.0.0.1:62047_solr-n_0000000000) starting
[junit4] 2> 2476683 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2476690 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2476696 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2476703 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2476709 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2476717 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2476730 T6689 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2476731 T6689 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62047_solr
[junit4] 2> 2476731 T6688 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2476735 T6635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2476738 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2476739 T6688 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"recovering"}
[junit4] 2> 2476739 T6688 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2476744 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2476746 T6681 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> 2476801 T6635 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2476805 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2476809 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2476811 T6688 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "base_url":"http://127.0.0.1/solr",
[junit4] 2> "node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "core":"core1",
[junit4] 2> "roles":"",
[junit4] 2> "state":"active"}
[junit4] 2> 2476811 T6688 oasc.Overseer$ClusterStateUpdater.updateState node=core_node1 is already registered
[junit4] 2> 2476811 T6688 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
[junit4] 2> 2476817 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2476949 T6681 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> 2476998 T6676 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef30160000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2477002 T6676 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef30160003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2477002 T6635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62047 62047
[junit4] 2> 2479827 T6675 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62047 62047
[junit4] 2> 2479830 T6635 oas.SolrTestCaseJ4.tearDown ###Ending testStateChange
[junit4] 2> 2479831 T6688 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62047_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2479831 T6690 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2479843 T6635 oas.SolrTestCaseJ4.setUp ###Starting testShardAssignment
[junit4] 2> 2479846 T6635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2479847 T6691 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2479973 T6635 oasc.ZkTestServer.run start zk server on port:62062
[junit4] 2> 2479976 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2479983 T6697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@22f27 name:ZooKeeperConnection Watcher:127.0.0.1:62062 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2479984 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2479988 T6692 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef3d360000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2479991 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2479994 T6699 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ee3b45 name:ZooKeeperConnection Watcher:127.0.0.1:62062 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2479995 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2479995 T6635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2480004 T6692 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef3d360001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2480006 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2480009 T6701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@149011f name:ZooKeeperConnection Watcher:127.0.0.1:62062/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2480010 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2480010 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2480016 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2480018 T6703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@504436 name:ZooKeeperConnection Watcher:127.0.0.1:62062/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2480020 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2480021 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2480024 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2480033 T6635 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62062_solr
[junit4] 2> 2480033 T6635 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2480039 T6635 oasc.Overseer.start Overseer (id=91580450513223683-127.0.0.1:62062_solr-n_0000000000) starting
[junit4] 2> 2480044 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2480050 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2480057 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2480065 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2480072 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2480082 T6635 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2480097 T6705 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2480098 T6635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2480099 T6705 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62062_solr
[junit4] 2> 2480100 T6704 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2480105 T6635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2480109 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2480117 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2480121 T6707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16eb1cb name:ZooKeeperConnection Watcher:127.0.0.1:62062/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2480122 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2480125 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2480131 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1
[junit4] 2> 2480137 T6707 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2480138 T6701 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2480143 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2480147 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2480149 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core1",
[junit4] 2> "core_node_name":"node1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2480149 T6704 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 2480149 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2480155 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2480159 T6707 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> 2480159 T6701 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> 2480770 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2480790 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 2480804 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2480809 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2480809 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2480817 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core2",
[junit4] 2> "core_node_name":"node2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2480817 T6704 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2480817 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2480826 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2480957 T6707 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> 2480957 T6701 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> 2481435 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2481453 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2481464 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2481464 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2481464 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2481467 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2481470 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2481478 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core3",
[junit4] 2> "core_node_name":"node3",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2481478 T6704 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2481478 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2481484 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2481616 T6701 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> 2481616 T6707 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> 2482095 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2482110 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2482122 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482123 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482123 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482127 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482127 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2482135 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core4",
[junit4] 2> "core_node_name":"node4",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2482135 T6704 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2482135 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2482141 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482271 T6701 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> 2482272 T6707 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> 2482753 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 2482770 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482770 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482770 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482774 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2482775 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core5",
[junit4] 2> "core_node_name":"node5",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2482775 T6704 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2482775 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2482781 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2482912 T6701 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> 2482912 T6707 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> 2483397 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2483415 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2483417 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2483417 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2483418 T6704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2483419 T6704 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "node_name":"127.0.0.1",
[junit4] 2> "core":"core6",
[junit4] 2> "core_node_name":"node6",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "base_url":"http://127.0.0.1/solr/"}
[junit4] 2> 2483419 T6704 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2483419 T6704 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2483425 T6703 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2483556 T6701 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> 2483557 T6707 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> 2484042 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2484057 T6692 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef3d360002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2484059 T6707 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2484060 T6707 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard3/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2484061 T6707 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard2/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2484061 T6707 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> 2484066 T6635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62062 62062
[junit4] 2> 2486889 T6691 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62062 62062
[junit4] 2> 2486892 T6635 oas.SolrTestCaseJ4.tearDown ###Ending testShardAssignment
[junit4] 2> 2486893 T6704 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62062_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2486894 T6708 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2486902 T6635 oas.SolrTestCaseJ4.setUp ###Starting testShardLeaderChange
[junit4] 2> 2486904 T6635 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2486905 T6709 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2487031 T6635 oasc.ZkTestServer.run start zk server on port:62080
[junit4] 2> 2487035 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487048 T6715 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd9807 name:ZooKeeperConnection Watcher:127.0.0.1:62080/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487048 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487051 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487055 T6717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13af677 name:ZooKeeperConnection Watcher:127.0.0.1:62080 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487055 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487060 T6710 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef58c80001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2487061 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487064 T6719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1244375 name:ZooKeeperConnection Watcher:127.0.0.1:62080 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487064 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487066 T6635 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2487073 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2487074 T6710 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455bef58c80002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2487083 T6635 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487084 T6720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487088 T6722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dcccbf name:ZooKeeperConnection Watcher:127.0.0.1:62080/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487088 T6635 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487089 T6724 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10646eb name:ZooKeeperConnection Watcher:127.0.0.1:62080/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487090 T6720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487090 T6635 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2487091 T6720 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2487097 T6635 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2487097 T6720 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2487102 T6635 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2487107 T6720 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62080_solr
[junit4] 2> 2487107 T6635 oascc.SolrZkClient.makePath makePath: /live_nodes/node1
[junit4] 2> 2487107 T6720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2487115 T6722 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 2487115 T6720 oasc.Overseer.start Overseer (id=91580450975776772-127.0.0.1:62080_solr-n_0000000000) starting
[junit4] 2> 2487117 T6635 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2487119 T6720 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2487127 T6720 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2487132 T6720 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2487138 T6720 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2487144 T6720 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2487151 T6720 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2487162 T6720 oasc.OverseerTest$OverseerRestarter.run Killing overseer.
[junit4] 2> 2487162 T6726 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2487167 T6720 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2487170 T6728 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@396557 name:ZooKeeperConnection Watcher:127.0.0.1:62080/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2487171 T6720 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2487171 T6726 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91580450975776772-127.0.0.1:62080_solr-n_0000000000) am no longer a leader.
[junit4] 2> 2487172 T6726 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62080_solr
[junit4] 2> 2487172 T6726 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /roles.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:226)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:223)
[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:223)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:299)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:212)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 2487179 T6720 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:62080_solr
[junit4] 2> 2487181 T6720 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2487184 T6720 oasc.Overseer.start Overseer (id=91580450975776773-127.0.0.1:62080_solr-n_0000000001) starting
[junit4] 2> 2487209 T6730 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2487210 T6730 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:62080_solr
[junit4] 2> 2487211 T6729 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2487216 T6729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2487217 T6729 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> 2487217 T6729 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 2487217 T6729 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2487223 T6728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2487226 T6722 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> 2487751 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2487769 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2487780 T6728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2487785 T6635 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2487785 T6729 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2487785 T6728 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2487794 T6729 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://
[...truncated too long message...]
unit4] 2> 2513079 T7047 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> 2513117 T7032 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455befb1d70002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2513120 T7047 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 2513121 T7032 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455befb1d70004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2513125 T7032 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455befb1d70003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 2513125 T6635 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62401 62401
[junit4] 2> 2515183 T7031 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:62401 62401
[junit4] 2> 2515185 T6635 oas.SolrTestCaseJ4.tearDown ###Ending testBadQueueItem
[junit4] 2> 2515185 T7044 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:62401_solr
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2515187 T7048 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
[junit4] 2>
[junit4] 2> 2515187 T6635 oas.SolrTestCaseJ4.initCore ####initCore
[junit4] 2> 2515189 T6635 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4] 2> 2517929 T6635 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.OverseerTest-C0C61B515A14DEBF-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=DefaultSimilarity, locale=ar_EG, timezone=MST
[junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_51 (32-bit)/cpus=2,threads=1,free=74702672,total=327938048
[junit4] 2> NOTE: All tests run in this JVM: [TestSort, TestConfigSets, TestCollationField, MoreLikeThisHandlerTest, TestPartialUpdateDeduplication, BasicDistributedZkTest, TermsComponentTest, DistributedQueryComponentCustomSortTest, CoreMergeIndexesAdminHandlerTest, TestDocBasedVersionConstraints, CustomCollectionTest, TestLRUCache, PreAnalyzedFieldTest, ZkNodePropsTest, DocValuesMultiTest, ResourceLoaderTest, LegacyHTMLStripCharFilterTest, WordBreakSolrSpellCheckerTest, UUIDFieldTest, DistributedDebugComponentTest, TestConfig, SignatureUpdateProcessorFactoryTest, ClusterStateTest, NotRequiredUniqueKeyTest, PeerSyncTest, MultiTermTest, TestCollationFieldDocValues, CacheHeaderTest, RequestHandlersTest, TestCollectionAPI, TestCollationKeyRangeQueries, TestQueryUtils, TestStressReorder, DocExpirationUpdateProcessorFactoryTest, SliceStateTest, DateMathParserTest, TriLevelCompositeIdRoutingTest, TestImplicitCoreProperties, SolrInfoMBeanTest, SolrIndexConfigTest, PluginInfoTest, TestDistribDocBasedVersion, TestZkChroot, FieldAnalysisRequestHandlerTest, TestManagedStopFilterFactory, BJQParserTest, TestCopyFieldCollectionResource, TestComplexPhraseQParserPlugin, TestSolrXmlPersistor, TestFastOutputStream, FieldMutatingUpdateProcessorTest, TestLMJelinekMercerSimilarityFactory, BlockDirectoryTest, TestLazyCores, TestPseudoReturnFields, TestStressRecovery, TestIndexingPerformance, TestUtils, CurrencyFieldXmlFileTest, TestWriterPerf, TestBM25SimilarityFactory, EnumFieldTest, TestHighFrequencyDictionaryFactory, TestStressLucene, TestSolrQueryParser, TestArbitraryIndexDir, DeleteReplicaTest, PrimUtilsTest, TestDistributedGrouping, DistributedQueryComponentOptimizationTest, StandardRequestHandlerTest, TestXIncludeConfig, UnloadDistributedZkTest, NumericFieldsTest, HighlighterConfigTest, TestRealTimeGet, HdfsBasicDistributedZk2Test, TestFieldTypeCollectionResource, TestAddFieldRealTimeGet, OutputWriterTest, TestCustomSort, TestRangeQuery, TestPostingsSolrHighlighter, TestSolrJ, DistanceFunctionTest, PolyFieldTest, TestOmitPositions, TermVectorComponentTest, DOMUtilTest, DistributedQueryElevationComponentTest, SimplePostToolTest, HdfsDirectoryTest, TestInitQParser, TestPHPSerializedResponseWriter, TestFieldSortValues, TestSerializedLuceneMatchVersion, TestSolrXMLSerializer, TestClassNameShortening, CSVRequestHandlerTest, AutoCommitTest, TestDynamicFieldResource, TestHighlightDedupGrouping, UniqFieldsUpdateProcessorFactoryTest, TestPerFieldSimilarity, ZkSolrClientTest, TestSearcherReuse, TestDocumentBuilder, TestCharFilters, SuggesterTSTTest, ChaosMonkeySafeLeaderTest, DirectSolrConnectionTest, TestReloadAndDeleteDocs, TestCSVLoader, TestFieldResource, SpellCheckComponentTest, SuggesterTest, TestSchemaVersionResource, StressHdfsTest, IndexSchemaRuntimeFieldTest, TestSolrXml, SyncSliceTest, BlockCacheTest, TestManagedSchema, TestUpdate, TestRecoveryHdfs, ShardSplitTest, OpenExchangeRatesOrgProviderTest, TestOverriddenPrefixQueryForCustomFieldType, TestSimpleQParserPlugin, TestCoreDiscovery, TestSuggestSpellingConverter, TestDefaultSimilarityFactory, LukeRequestHandlerTest, TestManagedResource, OverseerCollectionProcessorTest, SolrCmdDistributorTest, ShardRoutingCustomTest, HardAutoCommitTest, AddSchemaFieldsUpdateProcessorFactoryTest, AsyncMigrateRouteKeyTest, TestRandomDVFaceting, TestRTGBase, RAMDirectoryFactoryTest, TestBinaryResponseWriter, ShardRoutingTest, ParsingFieldUpdateProcessorsTest, BadCopyFieldTest, BasicFunctionalityTest, DistribDocExpirationUpdateProcessorTest, CoreAdminHandlerTest, TestStressVersions, HighlighterTest, TestLFUCache, ExternalFileFieldSortTest, HdfsRecoveryZkTest, SolrTestCaseJ4Test, CollectionsAPIDistributedZkTest, TestAnalyzedSuggestions, HdfsUnloadDistributedZkTest, TestManagedResourceStorage, TestTrie, DistributedSuggestComponentTest, SpellCheckCollatorTest, TestAnalyzeInfixSuggestions, TestLMDirichletSimilarityFactory, DeleteInactiveReplicaTest, ClusterStateUpdateTest, DocumentAnalysisRequestHandlerTest, TestValueSourceCache, AnalysisErrorHandlingTest, ZkControllerTest, TestFunctionQuery, TestMergePolicyConfig, MinimalSchemaTest, AssignTest, XsltUpdateRequestHandlerTest, TestFiltering, CursorPagingTest, TestNoOpRegenerator, InfoHandlerTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ZkCLITest, ReturnFieldsTest, BasicDistributedZk2Test, OpenCloseCoreStressTest, OverseerTest]
[junit4] Completed in 66.41s, 9 tests, 1 error <<< FAILURES!
[...truncated 602 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1282: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:908: There were test failures: 387 suites, 1619 tests, 1 error, 42 ignored (21 assumptions)
Total time: 101 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_51 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_60-ea-b13) -
Build # 3869 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3869/
Java: 64bit/jdk1.7.0_60-ea-b13 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch
Error Message:
commitWithin did not work expected:<68> but was:<67>
Stack Trace:
java.lang.AssertionError: commitWithin did not work expected:<68> but was:<67>
at __randomizedtesting.SeedInfo.seed([75939EC30A753627:F47510DB7D2A561B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:357)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 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:65)
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:360)
at java.lang.Thread.run(Thread.java:744)
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
document count mismatch. control=34 sum(shards)=36 cloudClient=36
Stack Trace:
java.lang.AssertionError: document count mismatch. control=34 sum(shards)=36 cloudClient=36
at __randomizedtesting.SeedInfo.seed([75939EC30A753627:F47510DB7D2A561B]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1280)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1206)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:220)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.GeneratedMethodAccessor40.invoke(Unknown Source)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 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:65)
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:360)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 11106 lines...]
[junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\init-core-data-001
[junit4] 2> 1659303 T6116 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /g_cb/
[junit4] 2> 1659308 T6116 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 1659310 T6116 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1659311 T6117 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1659391 T6116 oasc.ZkTestServer.run start zk server on port:51954
[junit4] 2> 1659393 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1659399 T6123 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61bfda9 name:ZooKeeperConnection Watcher:127.0.0.1:51954 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1659399 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1659399 T6116 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1659403 T6118 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455dd3e1f10000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 1659406 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1659408 T6125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9c731e7 name:ZooKeeperConnection Watcher:127.0.0.1:51954/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1659408 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1659408 T6116 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1659413 T6116 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1659417 T6116 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1659420 T6116 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1659424 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1659424 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1659430 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1659430 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1659435 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1659435 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1659439 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1659439 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1659444 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1659444 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1659448 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1659448 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1659452 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 1659452 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 1659456 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1659456 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1659463 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1659463 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1659469 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1659469 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1659473 T6116 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1659473 T6116 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1659478 T6118 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455dd3e1f10001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 1660936 T6116 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1660940 T6116 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51961
[junit4] 2> 1660941 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1660941 T6116 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1660941 T6116 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002
[junit4] 2> 1660941 T6116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002\'
[junit4] 2> 1660969 T6116 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002\solr.xml
[junit4] 2> 1661022 T6116 oasc.CoreContainer.<init> New CoreContainer 1147299393
[junit4] 2> 1661022 T6116 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002\]
[junit4] 2> 1661024 T6116 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1661024 T6116 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1661024 T6116 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1661024 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1661024 T6116 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1661025 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1661025 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1661025 T6116 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1661025 T6116 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1661025 T6116 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1661025 T6116 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1661025 T6116 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1661027 T6116 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51954/solr
[junit4] 2> 1661027 T6116 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1661029 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1661042 T6136 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1827587a name:ZooKeeperConnection Watcher:127.0.0.1:51954 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1661042 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1661044 T6118 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455dd3e1f10002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 1661046 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1661047 T6138 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@aadbac5 name:ZooKeeperConnection Watcher:127.0.0.1:51954/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1661048 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1661050 T6116 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1661055 T6116 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1661060 T6116 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 1661065 T6116 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 1661070 T6116 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 1661075 T6116 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1661077 T6116 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51961_g_cb
[junit4] 2> 1661078 T6116 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51961_g_cb
[junit4] 2> 1661082 T6116 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 1661086 T6116 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1661092 T6116 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51961_g_cb
[junit4] 2> 1661092 T6116 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1661095 T6116 oasc.Overseer.start Overseer (id=91582532041113603-127.0.0.1:51961_g_cb-n_0000000000) starting
[junit4] 2> 1661099 T6116 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1661116 T6140 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1661117 T6116 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1661117 T6140 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:51961_g_cb
[junit4] 2> 1661121 T6116 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1661124 T6116 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1661128 T6139 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1661134 T6141 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 1661134 T6141 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1661135 T6141 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1661135 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1661138 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1661138 T6139 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51961/g_cb",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51961_g_cb",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1661138 T6139 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1661138 T6139 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1661143 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1661144 T6138 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> 1661933 T6141 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1661933 T6141 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1661934 T6141 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1661934 T6141 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1661936 T6141 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1661936 T6141 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002\collection1\'
[junit4] 2> 1661939 T6141 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 1661939 T6141 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 1661941 T6141 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 1661998 T6141 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
[junit4] 2> 1662035 T6141 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1662037 T6141 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1662045 T6141 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1662376 T6141 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1662377 T6141 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1662377 T6141 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1662386 T6141 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1662388 T6141 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1662403 T6141 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1662407 T6141 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1662411 T6141 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1662413 T6141 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1662413 T6141 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1662413 T6141 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1662415 T6141 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1662415 T6141 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1662415 T6141 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 1662415 T6141 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1662415 T6141 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-002\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/control/data\
[junit4] 2> 1662415 T6141 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65c41bbe
[junit4] 2> 1662415 T6141 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/control/data\
[junit4] 2> 1662415 T6141 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/control/data\index/
[junit4] 2> 1662415 T6141 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
[junit4] 2> 1662417 T6141 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/control/data\index
[junit4] 2> 1662417 T6141 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1662417 T6141 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c4c56b3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@764c9e1b),segFN=segments_1,generation=1}
[junit4] 2> 1662417 T6141 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1662420 T6141 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1662421 T6141 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1662421 T6141 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1662421 T6141 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1662421 T6141 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1662422 T6141 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1662422 T6141 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1662422 T6141 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1662422 T6141 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1662422 T6141 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1662422 T6141 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1662422 T6141 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1662422 T6141 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1662423 T6141 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1662423 T6141 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1662423 T6141 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1662432 T6141 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1662436 T6141 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1662436 T6141 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1662438 T6141 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1662439 T6141 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c4c56b3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@764c9e1b),segFN=segments_1,generation=1}
[junit4] 2> 1662439 T6141 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1662440 T6141 oass.SolrIndexSearcher.<init> Opening Searcher@33a67680[collection1] main
[junit4] 2> 1662440 T6141 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1662441 T6141 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1662441 T6141 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1662442 T6141 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1662442 T6141 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1662442 T6141 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1662443 T6141 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1662443 T6141 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1662443 T6141 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1662443 T6141 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1662448 T6141 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1662450 T6116 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 1662450 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1662453 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1662454 T6142 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33a67680[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1662455 T6145 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51961/g_cb collection:control_collection shard:shard1
[junit4] 2> 1662457 T6145 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1662464 T6147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2adf4f35 name:ZooKeeperConnection Watcher:127.0.0.1:51954/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1662465 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1662468 T6116 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1662475 T6116 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 1662570 T6145 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1662755 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662757 T6145 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1662757 T6145 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C740 name=collection1 org.apache.solr.core.SolrCore@3fbc3bf5 url=http://127.0.0.1:51961/g_cb/collection1 node=127.0.0.1:51961_g_cb C740_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:51961/g_cb, core=collection1, node_name=127.0.0.1:51961_g_cb}
[junit4] 2> 1662757 T6145 C740 P51961 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51961/g_cb/collection1/
[junit4] 2> 1662757 T6145 C740 P51961 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1662757 T6145 C740 P51961 oasc.SyncStrategy.syncToMe http://127.0.0.1:51961/g_cb/collection1/ has no replicas
[junit4] 2> 1662758 T6145 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51961/g_cb/collection1/ shard1
[junit4] 2> 1662758 T6145 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1662758 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1662763 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662764 T6147 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> 1662764 T6138 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> 1662770 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662771 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1662775 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662858 T6138 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> 1662858 T6147 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> 1662893 T6145 oasc.ZkController.register We are http://127.0.0.1:51961/g_cb/collection1/ and leader is http://127.0.0.1:51961/g_cb/collection1/
[junit4] 2> 1662893 T6145 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51961/g_cb
[junit4] 2> 1662893 T6145 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1662893 T6145 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 1662893 T6145 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1662895 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662895 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662896 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662897 T6145 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1662898 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1662899 T6139 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51961/g_cb",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51961_g_cb",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1662902 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1662986 T6138 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> 1662986 T6147 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> 1663972 T6116 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 1663973 T6116 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1663976 T6116 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51973
[junit4] 2> 1663977 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1663977 T6116 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1663978 T6116 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003
[junit4] 2> 1663978 T6116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003\'
[junit4] 2> 1664005 T6116 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003\solr.xml
[junit4] 2> 1664054 T6116 oasc.CoreContainer.<init> New CoreContainer 1351651150
[junit4] 2> 1664055 T6116 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003\]
[junit4] 2> 1664055 T6116 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1664056 T6116 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1664056 T6116 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1664056 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1664056 T6116 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1664057 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1664057 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1664057 T6116 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1664057 T6116 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1664058 T6116 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1664058 T6116 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1664058 T6116 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1664058 T6116 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51954/solr
[junit4] 2> 1664058 T6116 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1664061 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1664070 T6158 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42b07334 name:ZooKeeperConnection Watcher:127.0.0.1:51954 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1664070 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1664073 T6118 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455dd3e1f10005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 1664074 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1664076 T6160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11e903e2 name:ZooKeeperConnection Watcher:127.0.0.1:51954/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1664076 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1664087 T6116 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1664888 T6116 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51973_g_cb
[junit4] 2> 1664890 T6116 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51973_g_cb
[junit4] 2> 1664894 T6160 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1664895 T6147 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1664895 T6138 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1664908 T6161 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1664908 T6161 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1664910 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1664910 T6161 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1664910 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1664911 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1664912 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1664913 T6139 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51973/g_cb",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51973_g_cb",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1664913 T6139 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1664913 T6139 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1664918 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1664919 T6160 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> 1664919 T6138 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> 1664919 T6147 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> 1665735 T6161 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1665735 T6161 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1665736 T6161 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1665737 T6161 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1665738 T6161 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1665738 T6161 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003\collection1\'
[junit4] 2> 1665740 T6161 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 1665742 T6161 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 1665742 T6161 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 1665796 T6161 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
[junit4] 2> 1665837 T6161 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1665841 T6161 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1665849 T6161 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1666279 T6161 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1666280 T6161 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1666281 T6161 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1666302 T6161 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1666305 T6161 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1666328 T6161 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1666335 T6161 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1666343 T6161 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1666345 T6161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1666345 T6161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1666345 T6161 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1666346 T6161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1666346 T6161 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1666346 T6161 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1666346 T6161 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1666348 T6161 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-003\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty1\
[junit4] 2> 1666348 T6161 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65c41bbe
[junit4] 2> 1666350 T6161 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty1\
[junit4] 2> 1666350 T6161 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty1\index/
[junit4] 2> 1666350 T6161 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
[junit4] 2> 1666351 T6161 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty1\index
[junit4] 2> 1666351 T6161 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1666352 T6161 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@67a3b3e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20828b6f),segFN=segments_1,generation=1}
[junit4] 2> 1666352 T6161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1666357 T6161 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1666358 T6161 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1666358 T6161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1666358 T6161 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1666358 T6161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1666358 T6161 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1666360 T6161 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1666360 T6161 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1666360 T6161 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1666361 T6161 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1666362 T6161 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1666362 T6161 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1666362 T6161 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1666363 T6161 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1666364 T6161 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1666364 T6161 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1666376 T6161 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1666381 T6161 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1666381 T6161 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1666382 T6161 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1666382 T6161 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@67a3b3e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20828b6f),segFN=segments_1,generation=1}
[junit4] 2> 1666382 T6161 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1666382 T6161 oass.SolrIndexSearcher.<init> Opening Searcher@f9682e8[collection1] main
[junit4] 2> 1666382 T6161 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1666384 T6161 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1666384 T6161 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1666385 T6161 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1666385 T6161 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1666385 T6161 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1666387 T6161 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1666387 T6161 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1666387 T6161 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1666387 T6161 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1666391 T6162 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f9682e8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1666395 T6161 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1666396 T6165 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51973/g_cb collection:collection1 shard:shard2
[junit4] 2> 1666397 T6116 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 1666397 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1666398 T6165 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1666421 T6165 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1666424 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666426 T6165 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1666426 T6165 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C741 name=collection1 org.apache.solr.core.SolrCore@168ce9bc url=http://127.0.0.1:51973/g_cb/collection1 node=127.0.0.1:51973_g_cb C741_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51973/g_cb, core=collection1, node_name=127.0.0.1:51973_g_cb}
[junit4] 2> 1666426 T6165 C741 P51973 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51973/g_cb/collection1/
[junit4] 2> 1666426 T6165 C741 P51973 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1666426 T6165 C741 P51973 oasc.SyncStrategy.syncToMe http://127.0.0.1:51973/g_cb/collection1/ has no replicas
[junit4] 2> 1666426 T6165 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51973/g_cb/collection1/ shard2
[junit4] 2> 1666427 T6165 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1666430 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1666437 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666439 T6138 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> 1666440 T6147 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> 1666443 T6160 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> 1666454 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1666461 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666552 T6138 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> 1666553 T6147 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> 1666553 T6160 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> 1666583 T6165 oasc.ZkController.register We are http://127.0.0.1:51973/g_cb/collection1/ and leader is http://127.0.0.1:51973/g_cb/collection1/
[junit4] 2> 1666583 T6165 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51973/g_cb
[junit4] 2> 1666583 T6165 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1666583 T6165 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 1666583 T6165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1666586 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666586 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666586 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666588 T6165 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1666589 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1666590 T6139 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51973/g_cb",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51973_g_cb",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1666595 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1666685 T6160 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> 1666686 T6138 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> 1666686 T6147 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> 1668250 T6116 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 1668251 T6116 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1668254 T6116 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51982
[junit4] 2> 1668256 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1668256 T6116 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1668256 T6116 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004
[junit4] 2> 1668256 T6116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004\'
[junit4] 2> 1668295 T6116 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004\solr.xml
[junit4] 2> 1668354 T6116 oasc.CoreContainer.<init> New CoreContainer 842067553
[junit4] 2> 1668354 T6116 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004\]
[junit4] 2> 1668355 T6116 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1668356 T6116 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1668356 T6116 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1668356 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1668356 T6116 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1668357 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1668357 T6116 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1668357 T6116 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1668357 T6116 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1668358 T6116 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1668358 T6116 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1668358 T6116 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1668358 T6116 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51954/solr
[junit4] 2> 1668358 T6116 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1668360 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1668376 T6176 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a723c05 name:ZooKeeperConnection Watcher:127.0.0.1:51954 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1668376 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1668383 T6118 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1455dd3e1f10007, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[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> 1668385 T6116 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1668387 T6178 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cbd6df9 name:ZooKeeperConnection Watcher:127.0.0.1:51954/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1668387 T6116 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1668398 T6116 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1669280 T6116 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51982_g_cb
[junit4] 2> 1669281 T6116 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51982_g_cb
[junit4] 2> 1669287 T6160 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1669287 T6147 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1669287 T6138 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1669288 T6178 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1669301 T6179 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 1669301 T6179 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1669303 T6179 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1669303 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669304 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669304 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669307 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1669308 T6139 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51982/g_cb",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51982_g_cb",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 1669308 T6139 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1669308 T6139 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1669313 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1669314 T6178 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1669315 T6138 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1669315 T6147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1669315 T6160 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1670181 T6179 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1670181 T6179 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1670182 T6179 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1670182 T6179 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1670184 T6179 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1670184 T6179 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004\collection1\'
[junit4] 2> 1670188 T6179 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 1670190 T6179 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 1670192 T6179 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-75939EC30A753627-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 1670265 T6179 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
[junit4] 2> 1670317 T6179 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1670323 T6179 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1670333 T6179 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1670701 T6179 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1670702 T6179 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 1670703 T6179 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1670711 T6179 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1670713 T6179 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1670732 T6179 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1670735 T6179 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1670740 T6179 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1670741 T6179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1670741 T6179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1670741 T6179 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1670743 T6179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1670743 T6179 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1670743 T6179 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 1670743 T6179 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1670745 T6179 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-004\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty2\
[junit4] 2> 1670745 T6179 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@65c41bbe
[junit4] 2> 1670745 T6179 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty2\
[junit4] 2> 1670745 T6179 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty2\index/
[junit4] 2> 1670745 T6179 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
[junit4] 2> 1670746 T6179 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-75939EC30A753627-001\tempDir-001/jetty2\index
[junit4] 2> 1670746 T6179 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=21, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1670746 T6179 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3aa2a38b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e69232f),segFN=segments_1,generation=1}
[junit4] 2> 1670747 T6179 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1670750 T6179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1670750 T6179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1670750 T6179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1670750 T6179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1670751 T6179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1670751 T6179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1670751 T6179 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1670752 T6179 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1670752 T6179 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1670752 T6179 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1670753 T6179 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1670753 T6179 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1670753 T6179 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1670753 T6179 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1670753 T6179 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1670754 T6179 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 1670760 T6179 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1670765 T6179 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1670765 T6179 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1670765 T6179 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 1670765 T6179 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3aa2a38b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2e69232f),segFN=segments_1,generation=1}
[junit4] 2> 1670765 T6179 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1670765 T6179 oass.SolrIndexSearcher.<init> Opening Searcher@6989bbb3[collection1] main
[junit4] 2> 1670765 T6179 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1670767 T6179 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 1670767 T6179 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 1670768 T6179 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 1670768 T6179 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 1670768 T6179 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1670769 T6179 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 1670769 T6179 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 1670769 T6179 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1670769 T6179 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1670775 T6180 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6989bbb3[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1670776 T6179 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1670777 T6183 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51982/g_cb collection:collection1 shard:shard1
[junit4] 2> 1670778 T6116 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4] 2> 1670778 T6116 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1670780 T6183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1670793 T6183 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1670797 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1670800 T6183 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1670800 T6183 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C742 name=collection1 org.apache.solr.core.SolrCore@53962eb4 url=http://127.0.0.1:51982/g_cb/collection1 node=127.0.0.1:51982_g_cb C742_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51982/g_cb, core=collection1, node_name=127.0.0.1:51982_g_cb}
[junit4] 2> 1670800 T6183 C742 P51982 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51982/g_cb/collection1/
[junit4] 2> 1670800 T6183 C742 P51982 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1670800 T6183 C742 P51982 oasc.SyncStrategy.syncToMe http://127.0.0.1:51982/g_cb/collection1/ has no replicas
[junit4] 2> 1670800 T6183 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51982/g_cb/collection1/ shard1
[junit4] 2> 1670801 T6183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1670825 T6139 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1670845 T6138 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 1670849 T6160 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1670849 T6138 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1670849 T6147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1670850 T6178 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updat
[...truncated too long message...]
eue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2625270 T9910 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> 2625273 T9910 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2625273 T9910 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2625273 T9910 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2625273 T9910 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.ChaosMonkeyNothingIsSafeTest-75939EC30A753627-001
[junit4] 2> NOTE: test params are: codec=Lucene46: {_version_=Lucene41(blocksize=128), rnd_b=Pulsing41(freqCutoff=10 minBlockSize=61 maxBlockSize=130), a_si=FSTOrd41, id=Pulsing41(freqCutoff=10 minBlockSize=61 maxBlockSize=130), a_t=Lucene41(blocksize=128)}, docValues:{}, sim=DefaultSimilarity, locale=fi, timezone=Canada/Yukon
[junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=250592592,total=409468928
[junit4] 2> NOTE: All tests run in this JVM: [QueryElevationComponentTest, TestCollationKeyRangeQueries, AnalysisAfterCoreReloadTest, TestUniqueKeyFieldResource, TestRTGBase, PreAnalyzedUpdateProcessorTest, DistanceFunctionTest, TestAnalyzedSuggestions, DistributedQueryComponentOptimizationTest, TestWordDelimiterFilterFactory, TestDefaultSearchFieldResource, TestSerializedLuceneMatchVersion, BadCopyFieldTest, TestUpdate, DeleteReplicaTest, TestRestManager, HighlighterConfigTest, SolrRequestParserTest, SolrIndexSplitterTest, TestDFRSimilarityFactory, TestSolr4Spatial, SolrInfoMBeanTest, SolrCoreTest, SoftAutoCommitTest, TestUtils, DistributedTermsComponentTest, TestMultiCoreConfBootstrap, TestQueryUtils, CoreMergeIndexesAdminHandlerTest, PrimUtilsTest, JsonLoaderTest, TestAnalyzeInfixSuggestions, DeleteShardTest, CursorMarkTest, SolrIndexConfigTest, MigrateRouteKeyTest, CoreAdminRequestStatusTest, TermVectorComponentDistributedTest, TestLMJelinekMercerSimilarityFactory, SliceStateTest, TestNonNRTOpen, TestSweetSpotSimilarityFactory, AddSchemaFieldsUpdateProcessorFactoryTest, HighlighterTest, TestExpandComponent, TestFoldingMultitermQuery, TestLuceneMatchVersion, RequestHandlersTest, StressHdfsTest, TestFieldTypeCollectionResource, TestGroupingSearch, FileBasedSpellCheckerTest, SpellCheckCollatorTest, CoreContainerCoreInitFailuresTest, SliceStateUpdateTest, FieldMutatingUpdateProcessorTest, DistributedQueryElevationComponentTest, TestSearcherReuse, HdfsBasicDistributedZk2Test, PathHierarchyTokenizerFactoryTest, TestSystemIdResolver, BlockCacheTest, CollectionsAPIAsyncDistributedZkTest, ShowFileRequestHandlerTest, SolrTestCaseJ4Test, BasicDistributedZk2Test, TestIndexingPerformance, TestStressRecovery, QueryParsingTest, UpdateParamsTest, TestDocumentBuilder, OutputWriterTest, TestPartialUpdateDeduplication, TestCoreDiscovery, TestSolrIndexConfig, TestTrie, DistribCursorPagingTest, MinimalSchemaTest, TestSolrXml, NotRequiredUniqueKeyTest, OpenExchangeRatesOrgProviderTest, EchoParamsTest, TestValueSourceCache, BasicZkTest, TestConfigSets, ScriptEngineTest, ShardRoutingTest, TestQuerySenderNoQuery, TestHashPartitioner, TestSort, TestPseudoReturnFields, TermsComponentTest, TestSchemaVersionResource, ReturnFieldsTest, RegexBoostProcessorTest, CurrencyFieldXmlFileTest, DocExpirationUpdateProcessorFactoryTest, TestSchemaNameResource, TestShardHandlerFactory, TestWriterPerf, OverseerCollectionProcessorTest, SSLMigrationTest, TestManagedStopFilterFactory, ResponseLogComponentTest, TestHighFrequencyDictionaryFactory, CircularListTest, DocValuesTest, SpellingQueryConverterTest, RecoveryZkTest, TestOmitPositions, TestRandomFaceting, DebugComponentTest, SchemaVersionSpecificBehaviorTest, StandardRequestHandlerTest, TestCollectionAPI, TestManagedSchemaFieldResource, TestFastLRUCache, AssignTest, HdfsUnloadDistributedZkTest, TestFreeTextSuggestions, TestCSVResponseWriter, DocumentBuilderTest, TimeZoneUtilsTest, ExternalFileFieldSortTest, TestQueryTypes, TestDistributedGrouping, TestCSVLoader, BadComponentTest, OverseerTest, FieldAnalysisRequestHandlerTest, TestMergePolicyConfig, LeaderElectionIntegrationTest, LukeRequestHandlerTest, IndexSchemaRuntimeFieldTest, DistribDocExpirationUpdateProcessorTest, UniqFieldsUpdateProcessorFactoryTest, PolyFieldTest, CurrencyFieldOpenExchangeTest, TestSolrCoreProperties, BJQParserTest, TestMaxScoreQueryParser, TestSolrQueryParserResource, CachingDirectoryFactoryTest, EnumFieldTest, SOLR749Test, ZkControllerTest, TestSolrJ, TestStressVersions, DistributedQueryComponentCustomSortTest, IndexBasedSpellCheckerTest, TestRandomDVFaceting, HdfsSyncSliceTest, TestStandardQParsers, ZkSolrClientTest, HdfsDirectoryTest, TestSchemaResource, TestLazyCores, BinaryUpdateRequestHandlerTest, TestNonDefinedSimilarityFactory, SuggesterTSTTest, IndexSchemaTest, TestPerFieldSimilarity, SolrXmlInZkTest, CopyFieldTest, OpenCloseCoreStressTest, TestSchemaSimilarityResource, ZkCLITest, AutoCommitTest, TestFastWriter, SpellPossibilityIteratorTest, TestRequestStatusCollectionAPI, TestFieldSortValues, OverseerRolesTest, TestArbitraryIndexDir, TestInitQParser, TestLFUCache, PingRequestHandlerTest, TestConfig, TestCollationField, SynonymTokenizerTest, TestIndexSearcher, TestCloudManagedSchemaAddField, OverseerStatusTest, TestOverriddenPrefixQueryForCustomFieldType, ClusterStateUpdateTest, FileUtilsTest, TestNoOpRegenerator, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, LeaderElectionTest, TestZkChroot, ShardRoutingCustomTest, TestDistributedSearch, TestFaceting, TestRecovery, DistributedSpellCheckComponentTest, TestRealTimeGet, TestStressReorder, TestJoin, TestReload, HardAutoCommitTest, TestRangeQuery, TestCoreContainer, SimpleFacetsTest, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, TestFunctionQuery, BasicFunctionalityTest, DirectUpdateHandlerTest, TestBadConfig, SimplePostToolTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SuggesterFSTTest, CoreAdminHandlerTest, SuggesterTest, TestStressLucene, SpatialFilterTest, SuggesterWFSTTest, NoCacheHeaderTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestAtomicUpdateErrorCases, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, DocumentAnalysisRequestHandlerTest, PrimitiveFieldTypeTest, XmlUpdateRequestHandlerTest, TermVectorComponentTest, MoreLikeThisHandlerTest, RequiredFieldsTest, TestSolrQueryParser, FastVectorHighlighterTest, LoggingHandlerTest, SolrPluginUtilsTest, TestJmxIntegration, UpdateRequestProcessorFactoryTest, JSONWriterTest, MBeansHandlerTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestComponentsName, SearchHandlerTest, TestBinaryResponseWriter, TestQuerySenderListener, AlternateDirectoryTest, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, TestDocSet, TestBinaryField, TestSearchPerf, NumericFieldsTest, TestElisionMultitermQuery, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestPhraseSuggestions, TestCharFilters, TestCodecSupport, TestXIncludeConfig, TestNumberUtils, TestLMDirichletSimilarityFactory, TestIBSimilarityFactory, TestBM25SimilarityFactory, TestDefaultSimilarityFactory, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, ResourceLoaderTest, TestFastOutputStream, URLClassifyProcessorTest, PluginInfoTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed in 67.59s, 1 test, 1 failure <<< FAILURES!
[...truncated 273 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1282: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:908: There were test failures: 387 suites, 1619 tests, 2 failures, 42 ignored (21 assumptions)
Total time: 88 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_60-ea-b13 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure