lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4549 - Failure
Date Fri, 27 Dec 2013 05:55:03 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4549/

1 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:43957/collection1, http://127.0.0.1:44012/collection1]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:43957/collection1, http://127.0.0.1:44012/collection1]
	at __randomizedtesting.SeedInfo.seed([68C6198AEAD98885:E92097929D86E8B9]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:352)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:640)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.queryServer(AbstractFullDistribZkTestBase.java:1325)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:542)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:521)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:305)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:117)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: no servers hosting shard: 
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:495)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:283)
	... 49 more




Build Log:
[...truncated 10500 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 896246 T3124 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 896252 T3124 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1388121557409
   [junit4]   2> 896254 T3124 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 896255 T3125 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 896357 T3124 oasc.ZkTestServer.run start zk server on port:43910
   [junit4]   2> 896358 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 896362 T3131 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2379b45d name:ZooKeeperConnection Watcher:127.0.0.1:43910 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 896363 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 896363 T3124 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 896368 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 896377 T3133 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a80c1ca name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 896378 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 896378 T3124 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 896382 T3124 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 896390 T3124 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 896392 T3124 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 896395 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 896396 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 896407 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 896407 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 896513 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 896513 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 896516 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 896517 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 896526 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 896527 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 896530 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 896530 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 896533 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 896534 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 896537 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 896538 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 896540 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 896541 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 896544 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 896545 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 896552 T3124 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 896553 T3124 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 896845 T3124 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 896851 T3124 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43913
   [junit4]   2> 896851 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 896852 T3124 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 896853 T3124 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711
   [junit4]   2> 896853 T3124 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/'
   [junit4]   2> 896914 T3124 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/solr.xml
   [junit4]   2> 897032 T3124 oasc.CoreContainer.<init> New CoreContainer 752966740
   [junit4]   2> 897033 T3124 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/]
   [junit4]   2> 897035 T3124 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 897035 T3124 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 897036 T3124 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 897036 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 897037 T3124 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 897037 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 897038 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 897038 T3124 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 897039 T3124 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 897060 T3124 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 897061 T3124 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 897061 T3124 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 897062 T3124 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43910/solr
   [junit4]   2> 897063 T3124 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 897064 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 897068 T3144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@776e1651 name:ZooKeeperConnection Watcher:127.0.0.1:43910 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 897069 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 897081 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 897081 T3126 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x143327e09a80002, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 
   [junit4]   2> 897088 T3146 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2dec9449 name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 897089 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 897092 T3124 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 897103 T3124 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 897108 T3124 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 897110 T3124 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43913_
   [junit4]   2> 897112 T3124 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43913_
   [junit4]   2> 897121 T3124 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 897136 T3124 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 897140 T3124 oasc.Overseer.start Overseer (id=90971934386814979-127.0.0.1:43913_-n_0000000000) starting
   [junit4]   2> 897151 T3124 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 897189 T3148 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 897190 T3124 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 897197 T3124 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 897199 T3124 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 897202 T3147 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 897209 T3149 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 897210 T3149 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 897211 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 897211 T3149 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 897213 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 897214 T3147 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:43913",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43913_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 897214 T3147 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 897214 T3147 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 897217 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 897219 T3146 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> 898214 T3149 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 898214 T3149 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/collection1
   [junit4]   2> 898214 T3149 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 898215 T3149 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 898215 T3149 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 898216 T3149 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/collection1/'
   [junit4]   2> 898218 T3149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/collection1/lib/README' to classloader
   [junit4]   2> 898218 T3149 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/collection1/lib/classes/' to classloader
   [junit4]   2> 898271 T3149 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 898317 T3149 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 898419 T3149 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 898431 T3149 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 899127 T3149 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 899140 T3149 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 899144 T3149 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 899160 T3149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 899165 T3149 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 899170 T3149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 899171 T3149 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 899172 T3149 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 899172 T3149 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 899174 T3149 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 899174 T3149 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 899174 T3149 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 899175 T3149 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1388121557711/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/control/data/
   [junit4]   2> 899175 T3149 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c0a628c
   [junit4]   2> 899176 T3149 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/control/data
   [junit4]   2> 899176 T3149 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/control/data/index/
   [junit4]   2> 899177 T3149 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 899177 T3149 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/control/data/index
   [junit4]   2> 899178 T3149 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=18.388671875, floorSegmentMB=1.8828125, forceMergeDeletesPctAllowed=23.195940358473806, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13814410758167722
   [junit4]   2> 899179 T3149 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@20d15c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56f08b3d),segFN=segments_1,generation=1}
   [junit4]   2> 899179 T3149 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 899184 T3149 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 899184 T3149 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 899185 T3149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 899185 T3149 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 899186 T3149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 899186 T3149 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 899187 T3149 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 899187 T3149 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 899187 T3149 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 899188 T3149 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 899189 T3149 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 899189 T3149 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 899189 T3149 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 899190 T3149 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 899190 T3149 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 899191 T3149 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 899192 T3149 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 899208 T3149 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 899215 T3149 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 899215 T3149 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 899216 T3149 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6117664221174919]
   [junit4]   2> 899217 T3149 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@20d15c2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56f08b3d),segFN=segments_1,generation=1}
   [junit4]   2> 899217 T3149 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 899217 T3149 oass.SolrIndexSearcher.<init> Opening Searcher@4847c260 main
   [junit4]   2> 899221 T3150 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4847c260 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 899224 T3149 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 899225 T3124 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 899226 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 899225 T3153 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43913 collection:control_collection shard:shard1
   [junit4]   2> 899227 T3153 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 899228 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 899230 T3155 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63d2fa82 name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 899231 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 899240 T3124 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 899244 T3153 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 899244 T3124 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 899254 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899254 T3153 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 899255 T3153 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C750 name=collection1 org.apache.solr.core.SolrCore@35801f5a url=http://127.0.0.1:43913/collection1 node=127.0.0.1:43913_ C750_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:43913, core=collection1, node_name=127.0.0.1:43913_}
   [junit4]   2> 899255 T3153 C750 P43913 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43913/collection1/
   [junit4]   2> 899255 T3153 C750 P43913 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 899255 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 899256 T3153 C750 P43913 oasc.SyncStrategy.syncToMe http://127.0.0.1:43913/collection1/ has no replicas
   [junit4]   2> 899256 T3153 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43913/collection1/ shard1
   [junit4]   2> 899256 T3153 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 899260 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899270 T3155 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> 899270 T3146 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> 899275 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 899278 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899382 T3146 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> 899382 T3155 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> 899428 T3153 oasc.ZkController.register We are http://127.0.0.1:43913/collection1/ and leader is http://127.0.0.1:43913/collection1/
   [junit4]   2> 899428 T3153 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43913
   [junit4]   2> 899428 T3153 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 899428 T3153 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 899429 T3153 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 899430 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899430 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899430 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899431 T3153 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 899432 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 899432 T3147 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:43913",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43913_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 899435 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 899524 T3124 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 899528 T3124 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43941
   [junit4]   2> 899529 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 899530 T3124 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 899530 T3124 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400
   [junit4]   2> 899531 T3124 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/'
   [junit4]   2> 899539 T3146 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> 899539 T3155 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> 899572 T3124 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/solr.xml
   [junit4]   2> 899671 T3124 oasc.CoreContainer.<init> New CoreContainer 1865241286
   [junit4]   2> 899672 T3124 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/]
   [junit4]   2> 899674 T3124 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 899674 T3124 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 899675 T3124 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 899675 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 899676 T3124 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 899676 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 899677 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 899677 T3124 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 899678 T3124 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 899696 T3124 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 899697 T3124 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 899697 T3124 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 899698 T3124 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43910/solr
   [junit4]   2> 899698 T3124 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 899700 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 899702 T3166 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@650d543 name:ZooKeeperConnection Watcher:127.0.0.1:43910 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 899703 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 899706 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 899714 T3168 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73326c9b name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 899714 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 899723 T3124 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 900728 T3124 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43941_
   [junit4]   2> 900734 T3124 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43941_
   [junit4]   2> 900738 T3155 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 900739 T3146 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 900739 T3168 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 900750 T3169 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 900751 T3169 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 900765 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 900765 T3169 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 900765 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 900766 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 900767 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 900768 T3147 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:43941",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43941_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 900768 T3147 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 900769 T3147 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 900772 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 900876 T3155 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> 900876 T3168 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> 900876 T3146 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> 901769 T3169 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 901769 T3169 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/collection1
   [junit4]   2> 901770 T3169 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 901771 T3169 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 901771 T3169 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 901772 T3169 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/collection1/'
   [junit4]   2> 901776 T3169 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/collection1/lib/README' to classloader
   [junit4]   2> 901777 T3169 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/collection1/lib/classes/' to classloader
   [junit4]   2> 901874 T3169 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 901964 T3169 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 902067 T3169 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 902082 T3169 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 902794 T3169 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 902807 T3169 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 902812 T3169 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 902827 T3169 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 902832 T3169 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 902837 T3169 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 902838 T3169 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 902838 T3169 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 902838 T3169 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 902839 T3169 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 902840 T3169 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 902840 T3169 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 902841 T3169 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1388121560400/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty1/
   [junit4]   2> 902841 T3169 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c0a628c
   [junit4]   2> 902842 T3169 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty1
   [junit4]   2> 902842 T3169 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty1/index/
   [junit4]   2> 902843 T3169 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 902843 T3169 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty1/index
   [junit4]   2> 902844 T3169 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=18.388671875, floorSegmentMB=1.8828125, forceMergeDeletesPctAllowed=23.195940358473806, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13814410758167722
   [junit4]   2> 902845 T3169 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5e28b175 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2981aa99),segFN=segments_1,generation=1}
   [junit4]   2> 902845 T3169 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 902851 T3169 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 902852 T3169 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 902852 T3169 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 902852 T3169 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 902853 T3169 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 902853 T3169 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 902854 T3169 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 902854 T3169 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 902854 T3169 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 902855 T3169 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 902856 T3169 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 902856 T3169 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 902857 T3169 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 902858 T3169 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 902858 T3169 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 902859 T3169 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 902860 T3169 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 902876 T3169 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 902882 T3169 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 902882 T3169 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 902883 T3169 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6117664221174919]
   [junit4]   2> 902884 T3169 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5e28b175 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2981aa99),segFN=segments_1,generation=1}
   [junit4]   2> 902884 T3169 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 902885 T3169 oass.SolrIndexSearcher.<init> Opening Searcher@3d5d97e main
   [junit4]   2> 902890 T3170 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d5d97e main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 902894 T3169 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 902895 T3124 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 902895 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 902895 T3173 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43941 collection:collection1 shard:shard1
   [junit4]   2> 902897 T3173 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 902919 T3173 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 902927 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 902927 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 902928 T3173 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 902928 T3173 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 902928 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C751 name=collection1 org.apache.solr.core.SolrCore@32d69e7a url=http://127.0.0.1:43941/collection1 node=127.0.0.1:43941_ C751_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:43941, core=collection1, node_name=127.0.0.1:43941_}
   [junit4]   2> 902928 T3173 C751 P43941 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43941/collection1/
   [junit4]   2> 902928 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 902929 T3173 C751 P43941 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 902929 T3173 C751 P43941 oasc.SyncStrategy.syncToMe http://127.0.0.1:43941/collection1/ has no replicas
   [junit4]   2> 902930 T3173 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43941/collection1/ shard1
   [junit4]   2> 902930 T3173 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 902932 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 902940 T3146 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> 902940 T3155 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> 902940 T3168 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> 902958 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 902968 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 903071 T3155 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> 903071 T3146 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> 903071 T3168 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> 903112 T3173 oasc.ZkController.register We are http://127.0.0.1:43941/collection1/ and leader is http://127.0.0.1:43941/collection1/
   [junit4]   2> 903112 T3173 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43941
   [junit4]   2> 903112 T3173 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 903113 T3173 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 903113 T3173 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 903114 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 903115 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 903115 T3173 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 903115 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 903117 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 903117 T3147 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:43941",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43941_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 903120 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 903214 T3124 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 903218 T3124 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43957
   [junit4]   2> 903218 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 903219 T3124 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 903219 T3124 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052
   [junit4]   2> 903220 T3124 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/'
   [junit4]   2> 903224 T3155 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> 903224 T3146 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> 903224 T3168 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> 903261 T3124 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/solr.xml
   [junit4]   2> 903360 T3124 oasc.CoreContainer.<init> New CoreContainer 298833088
   [junit4]   2> 903361 T3124 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/]
   [junit4]   2> 903364 T3124 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 903364 T3124 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 903365 T3124 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 903365 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 903365 T3124 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 903366 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 903366 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 903367 T3124 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 903367 T3124 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 903386 T3124 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 903387 T3124 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 903387 T3124 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 903388 T3124 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43910/solr
   [junit4]   2> 903388 T3124 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 903390 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 903392 T3184 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5edc9d9e name:ZooKeeperConnection Watcher:127.0.0.1:43910 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 903394 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 903397 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 903399 T3186 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4617b61a name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 903399 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 903409 T3124 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 904413 T3124 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43957_
   [junit4]   2> 904415 T3124 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43957_
   [junit4]   2> 904418 T3155 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 904418 T3168 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 904418 T3146 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 904418 T3186 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 904434 T3187 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 904434 T3187 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 904435 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 904435 T3187 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 904436 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 904436 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 904437 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 904438 T3147 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:43957",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43957_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 904438 T3147 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 904438 T3147 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 904441 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 904545 T3186 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> 904545 T3168 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> 904545 T3155 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> 904545 T3146 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> 905438 T3187 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 905438 T3187 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/collection1
   [junit4]   2> 905438 T3187 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 905439 T3187 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 905440 T3187 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 905441 T3187 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/collection1/'
   [junit4]   2> 905443 T3187 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/collection1/lib/classes/' to classloader
   [junit4]   2> 905444 T3187 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/collection1/lib/README' to classloader
   [junit4]   2> 905512 T3187 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 905579 T3187 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 905681 T3187 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 905693 T3187 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 906336 T3187 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 906345 T3187 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 906348 T3187 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 906360 T3187 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 906365 T3187 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 906369 T3187 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 906370 T3187 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 906372 T3187 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 906372 T3187 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 906373 T3187 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 906373 T3187 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 906374 T3187 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 906374 T3187 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1388121564052/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty2/
   [junit4]   2> 906374 T3187 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@c0a628c
   [junit4]   2> 906375 T3187 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty2
   [junit4]   2> 906375 T3187 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty2/index/
   [junit4]   2> 906376 T3187 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 906376 T3187 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty2/index
   [junit4]   2> 906376 T3187 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=18.388671875, floorSegmentMB=1.8828125, forceMergeDeletesPctAllowed=23.195940358473806, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13814410758167722
   [junit4]   2> 906377 T3187 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@16332b02 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41790815),segFN=segments_1,generation=1}
   [junit4]   2> 906377 T3187 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 906382 T3187 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 906382 T3187 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 906383 T3187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 906383 T3187 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 906383 T3187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 906383 T3187 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 906384 T3187 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 906384 T3187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 906384 T3187 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 906385 T3187 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 906385 T3187 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 906386 T3187 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 906386 T3187 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 906386 T3187 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 906387 T3187 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 906388 T3187 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 906388 T3187 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 906399 T3187 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 906403 T3187 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 906403 T3187 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 906404 T3187 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6117664221174919]
   [junit4]   2> 906404 T3187 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@16332b02 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41790815),segFN=segments_1,generation=1}
   [junit4]   2> 906405 T3187 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 906405 T3187 oass.SolrIndexSearcher.<init> Opening Searcher@270afc2c main
   [junit4]   2> 906409 T3188 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@270afc2c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 906412 T3187 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 906413 T3124 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0
   [junit4]   2> 906414 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 906413 T3191 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43957 collection:collection1 shard:shard2
   [junit4]   2> 906415 T3191 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 906429 T3191 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 906437 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906437 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906437 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906437 T3191 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 906438 T3191 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C752 name=collection1 org.apache.solr.core.SolrCore@9634038 url=http://127.0.0.1:43957/collection1 node=127.0.0.1:43957_ C752_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:43957, core=collection1, node_name=127.0.0.1:43957_}
   [junit4]   2> 906438 T3191 C752 P43957 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43957/collection1/
   [junit4]   2> 906438 T3191 C752 P43957 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 906438 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 906438 T3191 C752 P43957 oasc.SyncStrategy.syncToMe http://127.0.0.1:43957/collection1/ has no replicas
   [junit4]   2> 906439 T3191 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43957/collection1/ shard2
   [junit4]   2> 906439 T3191 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 906442 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906452 T3146 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> 906452 T3168 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> 906452 T3155 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> 906452 T3186 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> 906462 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 906465 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906568 T3146 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> 906568 T3186 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> 906568 T3155 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> 906568 T3168 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> 906615 T3191 oasc.ZkController.register We are http://127.0.0.1:43957/collection1/ and leader is http://127.0.0.1:43957/collection1/
   [junit4]   2> 906615 T3191 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43957
   [junit4]   2> 906615 T3191 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 906615 T3191 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 906615 T3191 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 906617 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906617 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906617 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906617 T3191 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 906618 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 906618 T3147 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:43957",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43957_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 906622 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 906694 T3124 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 906697 T3124 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43981
   [junit4]   2> 906698 T3124 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 906699 T3124 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 906699 T3124 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388121567570
   [junit4]   2> 906700 T3124 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388121567570/'
   [junit4]   2> 906725 T3155 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> 906725 T3186 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> 906725 T3168 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> 906725 T3146 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> 906741 T3124 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388121567570/solr.xml
   [junit4]   2> 906839 T3124 oasc.CoreContainer.<init> New CoreContainer 516351640
   [junit4]   2> 906840 T3124 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1388121567570/]
   [junit4]   2> 906842 T3124 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 906843 T3124 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 906843 T3124 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 906844 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 906844 T3124 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 906844 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 906845 T3124 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 906845 T3124 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 906846 T3124 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 906865 T3124 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 906865 T3124 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 906866 T3124 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 906866 T3124 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43910/solr
   [junit4]   2> 906867 T3124 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 906868 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 906870 T3202 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63555ff4 name:ZooKeeperConnection Watcher:127.0.0.1:43910 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 906871 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 906873 T3124 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 906880 T3204 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c0bfe15 name:ZooKeeperConnection Watcher:127.0.0.1:43910/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 906880 T3124 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 906885 T3124 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 907889 T3124 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43981_
   [junit4]   2> 907891 T3124 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43981_
   [junit4]   2> 907894 T3168 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 907895 T3186 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 907894 T3155 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 907894 T3204 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 907894 T3146 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 907931 T3205 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 907932 T3205 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 907937 T3205 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 907937 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 907938 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 907938 T3146 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 907946 T3147 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 907949 T3147 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

[...truncated too long message...]

8 T3204 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 971088 T3204 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 971089 T3204 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3/index;done=false>>]
   [junit4]   2> 971089 T3204 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3/index
   [junit4]   2> 971089 T3204 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3;done=false>>]
   [junit4]   2> 971089 T3204 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1388121557408/jetty3
   [junit4]   2> 971090 T3204 oasc.LeaderElector$1.process WARN  org.apache.solr.common.SolrException: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:63)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer.getInQueue(Overseer.java:1028)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:157)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:178)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.joinElection(LeaderElector.java:277)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.rejoinLeaderElection(ElectionContext.java:385)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:165)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:109)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer/queue
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:218)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$4.execute(SolrZkClient.java:215)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:215)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:92)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:86)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:61)
   [junit4]   2> 	... 18 more
   [junit4]   2> 
   [junit4]   2> 971091 T3204 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 971091 T3204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 971091 T3204 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 971092 T3204 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 971162 T3223 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=en_ZA, timezone=Asia/Riyadh
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=1,free=371689440,total=535822336
   [junit4]   2> NOTE: All tests run in this JVM: [EchoParamsTest, TestRealTimeGet, TestQueryUtils, DocValuesMissingTest, HdfsBasicDistributedZk2Test, SliceStateTest, ScriptEngineTest, DistributedDebugComponentTest, SynonymTokenizerTest, TestSearchPerf, TestRemoteStreaming, TestCoreContainer, DocValuesTest, TriLevelCompositeIdRoutingTest, SuggesterFSTTest, TestSolrIndexConfig, TestPHPSerializedResponseWriter, TestBadConfig, HdfsSyncSliceTest, RegexBoostProcessorTest, CircularListTest, NoFacetTest, CacheHeaderTest, AssignTest, SearchHandlerTest, SliceStateUpdateTest, TestSolrQueryParser, ResourceLoaderTest, TestShardHandlerFactory, ShardSplitTest, RangeFacetTest, TestBM25SimilarityFactory, HdfsChaosMonkeySafeLeaderTest, BasicDistributedZkTest, TestLRUCache, CSVRequestHandlerTest, StatelessScriptUpdateProcessorFactoryTest, BadComponentTest, PreAnalyzedUpdateProcessorTest, TestCollapseQParserPlugin, AutoCommitTest, TestMergePolicyConfig, QueryResultKeyTest, TestDistributedMissingSort, TestReversedWildcardFilterFactory, LukeRequestHandlerTest, ShowFileRequestHandlerTest, DirectUpdateHandlerOptimizeTest, SolrCoreTest, SuggesterTest, TestConfig, ExternalFileFieldSortTest, ExpressionTest, TestSuggestSpellingConverter, JsonLoaderTest, TestSolrDeletionPolicy1, TestFunctionQuery, UpdateParamsTest, OverseerTest, BasicFunctionalityTest, TestSchemaVersionResource, TestTrie, TestUniqueKeyFieldResource, WordBreakSolrSpellCheckerTest, TermVectorComponentTest, TestCloudManagedSchemaAddField, TestJmxMonitoredMap, URLClassifyProcessorTest, TestSort, TestRandomDVFaceting, PolyFieldTest, LeaderElectionTest, ClusterStateTest, TestModifyConfFiles, ResponseLogComponentTest, SolrInfoMBeanTest, EnumFieldTest, LegacyHTMLStripCharFilterTest, OverseerCollectionProcessorTest, TestDynamicFieldCollectionResource, UUIDFieldTest, TestCollationFieldDocValues, TestLFUCache, AbstractAnalyticsFacetTest, TestElisionMultitermQuery, TestHighFrequencyDictionaryFactory, BasicDistributedZk2Test]
   [junit4] Completed on J0 in 75.62s, 1 test, 1 error <<< FAILURES!

[...truncated 658 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:453: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:433: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:491: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1304: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:937: There were test failures: 357 suites, 1573 tests, 1 error, 34 ignored (6 assumptions)

Total time: 76 minutes 33 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message