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-4.x-Java7 - Build # 1596 - Still Failing
Date Mon, 16 Sep 2013 09:08:14 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1596/

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

Error Message:


Stack Trace:
java.lang.NullPointerException
	at __randomizedtesting.SeedInfo.seed([A4A792552AE49064:25411C4D5DBBF058]:0)
	at org.apache.solr.common.cloud.ZkCoreNodeProps.getBaseUrl(ZkCoreNodeProps.java:40)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.buildUrlMap(CloudSolrServer.java:406)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.directUpdate(CloudSolrServer.java:304)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:498)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.commit(AbstractFullDistribZkTestBase.java:1517)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:288)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:115)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	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)




Build Log:
[...truncated 10134 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 1301514 T3041 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1301520 T3041 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1379321786461
   [junit4]   2> 1301522 T3041 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1301523 T3042 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1301624 T3041 oasc.ZkTestServer.run start zk server on port:23478
   [junit4]   2> 1301625 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1301629 T3048 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70bae5a9 name:ZooKeeperConnection Watcher:127.0.0.1:23478 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1301629 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1301629 T3041 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1301645 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1301648 T3050 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72a808b7 name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1301648 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1301649 T3041 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1301659 T3041 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1301662 T3041 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1301665 T3041 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1301673 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1301674 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1301688 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1301688 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1301792 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1301793 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1301796 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1301797 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1301800 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1301800 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1301808 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1301809 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1301812 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1301813 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1301815 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1301816 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1301819 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1301820 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1301823 T3041 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1301823 T3041 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1302114 T3041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1302118 T3041 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42606
   [junit4]   2> 1302119 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1302119 T3041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1302120 T3041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772
   [junit4]   2> 1302120 T3041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/'
   [junit4]   2> 1302161 T3041 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/solr.xml
   [junit4]   2> 1302280 T3041 oasc.CoreContainer.<init> New CoreContainer 1099821272
   [junit4]   2> 1302281 T3041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/]
   [junit4]   2> 1302283 T3041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1302284 T3041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1302284 T3041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1302285 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1302285 T3041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1302286 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1302286 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1302287 T3041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1302287 T3041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1302288 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1302305 T3041 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1302306 T3041 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1302306 T3041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23478/solr
   [junit4]   2> 1302307 T3041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1302308 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1302311 T3061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b12cd2e name:ZooKeeperConnection Watcher:127.0.0.1:23478 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1302312 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1302322 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1302334 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1302336 T3063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49bb9696 name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1302336 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1302338 T3041 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1302347 T3041 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1302350 T3041 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1302358 T3041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42606_
   [junit4]   2> 1302360 T3041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42606_
   [junit4]   2> 1302363 T3041 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1302375 T3041 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1302383 T3041 oasc.Overseer.start Overseer (id=90395232597966851-127.0.0.1:42606_-n_0000000000) starting
   [junit4]   2> 1302387 T3041 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1302400 T3065 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1302401 T3041 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1302403 T3041 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1302410 T3041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1302413 T3064 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1302419 T3066 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1302419 T3066 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1302420 T3066 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1303916 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1303917 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42606_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42606"}
   [junit4]   2> 1303917 T3064 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1303918 T3064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1303939 T3063 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> 1304423 T3066 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1304423 T3066 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/collection1
   [junit4]   2> 1304424 T3066 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1304424 T3066 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1304425 T3066 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1304426 T3066 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/collection1/'
   [junit4]   2> 1304427 T3066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/collection1/lib/classes/' to classloader
   [junit4]   2> 1304428 T3066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/collection1/lib/README' to classloader
   [junit4]   2> 1304494 T3066 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1304560 T3066 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1304662 T3066 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1304674 T3066 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 1305361 T3066 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1305362 T3066 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1305363 T3066 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1305376 T3066 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1305380 T3066 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1305394 T3066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1305399 T3066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1305404 T3066 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1305405 T3066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1305405 T3066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1305406 T3066 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1305407 T3066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1305407 T3066 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1305407 T3066 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1305408 T3066 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379321786772/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/control/data/
   [junit4]   2> 1305408 T3066 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2c9d964f
   [junit4]   2> 1305409 T3066 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/control/data
   [junit4]   2> 1305410 T3066 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/control/data/index/
   [junit4]   2> 1305410 T3066 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1305410 T3066 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/control/data/index
   [junit4]   2> 1305411 T3066 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=83.4384765625, floorSegmentMB=2.0693359375, forceMergeDeletesPctAllowed=13.50847898249339, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5225840113678659
   [junit4]   2> 1305412 T3066 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7740c7b0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34ff399b),segFN=segments_1,generation=1}
   [junit4]   2> 1305412 T3066 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1305416 T3066 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1305417 T3066 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1305417 T3066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1305418 T3066 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1305418 T3066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1305418 T3066 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1305419 T3066 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1305419 T3066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1305420 T3066 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1305420 T3066 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1305421 T3066 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1305421 T3066 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1305422 T3066 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1305422 T3066 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1305423 T3066 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1305440 T3066 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1305446 T3066 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1305446 T3066 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1305447 T3066 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1305448 T3066 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7740c7b0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@34ff399b),segFN=segments_1,generation=1}
   [junit4]   2> 1305448 T3066 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1305449 T3066 oass.SolrIndexSearcher.<init> Opening Searcher@78f9fb5 main
   [junit4]   2> 1305453 T3067 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78f9fb5 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1305455 T3066 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1305455 T3066 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42606 collection:control_collection shard:shard1
   [junit4]   2> 1305456 T3066 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 1305465 T3066 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1305539 T3066 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1305565 T3066 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1305565 T3066 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1305566 T3066 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42606/collection1/
   [junit4]   2> 1305566 T3066 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1305566 T3066 oasc.SyncStrategy.syncToMe http://127.0.0.1:42606/collection1/ has no replicas
   [junit4]   2> 1305567 T3066 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42606/collection1/ shard1
   [junit4]   2> 1305567 T3066 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1306945 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1306968 T3063 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> 1307001 T3066 oasc.ZkController.register We are http://127.0.0.1:42606/collection1/ and leader is http://127.0.0.1:42606/collection1/
   [junit4]   2> 1307001 T3066 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42606
   [junit4]   2> 1307001 T3066 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1307002 T3066 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1307002 T3066 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1307004 T3066 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1307005 T3041 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1307006 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1307006 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1307016 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 1307018 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1307020 T3070 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19190ada name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1307020 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1307021 T3041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1307023 T3041 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1307311 T3041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1307314 T3041 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:30784
   [junit4]   2> 1307315 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1307316 T3041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1307316 T3041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963
   [junit4]   2> 1307317 T3041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/'
   [junit4]   2> 1307358 T3041 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/solr.xml
   [junit4]   2> 1307451 T3041 oasc.CoreContainer.<init> New CoreContainer 926671137
   [junit4]   2> 1307452 T3041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/]
   [junit4]   2> 1307454 T3041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1307455 T3041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1307455 T3041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1307456 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1307456 T3041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1307457 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1307457 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1307458 T3041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1307458 T3041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1307459 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1307474 T3041 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1307475 T3041 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1307475 T3041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23478/solr
   [junit4]   2> 1307476 T3041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1307477 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1307480 T3081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5572c04 name:ZooKeeperConnection Watcher:127.0.0.1:23478 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1307481 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1307495 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1307506 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1307508 T3083 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c48d292 name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1307508 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1307518 T3041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1308473 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1308474 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42606_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42606"}
   [junit4]   2> 1308487 T3063 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> 1308487 T3083 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> 1308487 T3070 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> 1308522 T3041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:30784_
   [junit4]   2> 1308524 T3041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:30784_
   [junit4]   2> 1308526 T3070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1308526 T3083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 1308526 T3063 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1308527 T3063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1308527 T3070 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1308535 T3083 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1308542 T3084 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1308543 T3084 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1308544 T3084 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1309991 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1309992 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:30784_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:30784"}
   [junit4]   2> 1309992 T3064 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1309993 T3064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1310006 T3063 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> 1310006 T3070 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> 1310006 T3083 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> 1310546 T3084 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1310546 T3084 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/collection1
   [junit4]   2> 1310547 T3084 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1310547 T3084 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1310548 T3084 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1310549 T3084 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/collection1/'
   [junit4]   2> 1310551 T3084 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/collection1/lib/README' to classloader
   [junit4]   2> 1310552 T3084 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/collection1/lib/classes/' to classloader
   [junit4]   2> 1310619 T3084 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1310686 T3084 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1310787 T3084 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1310799 T3084 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 1311482 T3084 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1311483 T3084 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1311484 T3084 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1311496 T3084 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1311501 T3084 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1311515 T3084 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1311520 T3084 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1311525 T3084 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1311526 T3084 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1311526 T3084 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1311527 T3084 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1311528 T3084 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1311528 T3084 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1311528 T3084 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1311529 T3084 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379321791963/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty1/
   [junit4]   2> 1311529 T3084 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2c9d964f
   [junit4]   2> 1311530 T3084 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty1
   [junit4]   2> 1311531 T3084 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty1/index/
   [junit4]   2> 1311531 T3084 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1311532 T3084 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty1/index
   [junit4]   2> 1311532 T3084 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=83.4384765625, floorSegmentMB=2.0693359375, forceMergeDeletesPctAllowed=13.50847898249339, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5225840113678659
   [junit4]   2> 1311533 T3084 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@443d4309 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ff6bca3),segFN=segments_1,generation=1}
   [junit4]   2> 1311534 T3084 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1311538 T3084 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1311539 T3084 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1311539 T3084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1311540 T3084 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1311540 T3084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1311540 T3084 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1311541 T3084 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1311542 T3084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1311542 T3084 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1311543 T3084 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1311544 T3084 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1311544 T3084 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1311545 T3084 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1311545 T3084 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1311546 T3084 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1311563 T3084 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1311568 T3084 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1311568 T3084 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1311569 T3084 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1311570 T3084 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@443d4309 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ff6bca3),segFN=segments_1,generation=1}
   [junit4]   2> 1311571 T3084 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1311571 T3084 oass.SolrIndexSearcher.<init> Opening Searcher@56b818a2 main
   [junit4]   2> 1311576 T3085 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@56b818a2 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1311579 T3084 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1311579 T3084 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:30784 collection:collection1 shard:shard1
   [junit4]   2> 1311580 T3084 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 1311591 T3084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1311617 T3084 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1311620 T3084 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1311620 T3084 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1311620 T3084 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:30784/collection1/
   [junit4]   2> 1311620 T3084 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1311621 T3084 oasc.SyncStrategy.syncToMe http://127.0.0.1:30784/collection1/ has no replicas
   [junit4]   2> 1311621 T3084 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:30784/collection1/ shard1
   [junit4]   2> 1311621 T3084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1313013 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1313034 T3063 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> 1313034 T3070 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> 1313034 T3083 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> 1313055 T3084 oasc.ZkController.register We are http://127.0.0.1:30784/collection1/ and leader is http://127.0.0.1:30784/collection1/
   [junit4]   2> 1313055 T3084 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:30784
   [junit4]   2> 1313055 T3084 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1313056 T3084 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1313056 T3084 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1313058 T3084 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1313059 T3041 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1313059 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1313060 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1313349 T3041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1313353 T3041 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32371
   [junit4]   2> 1313353 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1313354 T3041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1313355 T3041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009
   [junit4]   2> 1313355 T3041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/'
   [junit4]   2> 1313396 T3041 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/solr.xml
   [junit4]   2> 1313489 T3041 oasc.CoreContainer.<init> New CoreContainer 1206458062
   [junit4]   2> 1313490 T3041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/]
   [junit4]   2> 1313492 T3041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1313492 T3041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1313493 T3041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1313494 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1313494 T3041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1313495 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1313495 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1313496 T3041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1313496 T3041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1313497 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1313512 T3041 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1313512 T3041 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1313513 T3041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23478/solr
   [junit4]   2> 1313514 T3041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1313515 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1313518 T3097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@537ebe12 name:ZooKeeperConnection Watcher:127.0.0.1:23478 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1313518 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1313533 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1313544 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1313546 T3099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3bacccc5 name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1313546 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1313555 T3041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1314539 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1314540 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:30784_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:30784"}
   [junit4]   2> 1314554 T3063 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> 1314555 T3070 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> 1314555 T3099 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> 1314555 T3083 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> 1314558 T3041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32371_
   [junit4]   2> 1314560 T3041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32371_
   [junit4]   2> 1314568 T3099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1314568 T3083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1314568 T3070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1314568 T3063 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1314569 T3063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1314570 T3099 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1314570 T3083 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1314571 T3070 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1314578 T3100 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1314578 T3100 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1314579 T3100 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1316059 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1316060 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32371_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:32371"}
   [junit4]   2> 1316061 T3064 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1316061 T3064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1316108 T3063 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> 1316108 T3070 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> 1316108 T3099 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> 1316108 T3083 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> 1316582 T3100 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1316582 T3100 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/collection1
   [junit4]   2> 1316582 T3100 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1316583 T3100 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1316583 T3100 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1316584 T3100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/collection1/'
   [junit4]   2> 1316586 T3100 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/collection1/lib/classes/' to classloader
   [junit4]   2> 1316586 T3100 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/collection1/lib/README' to classloader
   [junit4]   2> 1316654 T3100 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1316721 T3100 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1316823 T3100 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1316835 T3100 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 1317530 T3100 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1317532 T3100 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1317533 T3100 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1317546 T3100 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1317550 T3100 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1317565 T3100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1317570 T3100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1317575 T3100 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1317576 T3100 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1317576 T3100 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1317576 T3100 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1317577 T3100 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1317578 T3100 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1317578 T3100 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1317579 T3100 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379321798009/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty2/
   [junit4]   2> 1317579 T3100 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2c9d964f
   [junit4]   2> 1317580 T3100 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty2
   [junit4]   2> 1317581 T3100 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty2/index/
   [junit4]   2> 1317581 T3100 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1317581 T3100 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty2/index
   [junit4]   2> 1317582 T3100 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=83.4384765625, floorSegmentMB=2.0693359375, forceMergeDeletesPctAllowed=13.50847898249339, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5225840113678659
   [junit4]   2> 1317583 T3100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1035c2da lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@729237ad),segFN=segments_1,generation=1}
   [junit4]   2> 1317583 T3100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1317588 T3100 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1317589 T3100 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1317589 T3100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1317590 T3100 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1317590 T3100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1317590 T3100 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1317591 T3100 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1317592 T3100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1317592 T3100 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1317593 T3100 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1317594 T3100 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1317594 T3100 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1317594 T3100 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1317595 T3100 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1317596 T3100 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1317611 T3100 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1317617 T3100 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1317617 T3100 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1317618 T3100 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1317619 T3100 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1035c2da lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@729237ad),segFN=segments_1,generation=1}
   [junit4]   2> 1317619 T3100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1317619 T3100 oass.SolrIndexSearcher.<init> Opening Searcher@b066998 main
   [junit4]   2> 1317625 T3101 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b066998 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1317627 T3100 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1317627 T3100 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32371 collection:collection1 shard:shard2
   [junit4]   2> 1317628 T3100 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 1317639 T3100 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1317658 T3100 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1317660 T3100 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1317661 T3100 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1317661 T3100 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32371/collection1/
   [junit4]   2> 1317661 T3100 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1317661 T3100 oasc.SyncStrategy.syncToMe http://127.0.0.1:32371/collection1/ has no replicas
   [junit4]   2> 1317662 T3100 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32371/collection1/ shard2
   [junit4]   2> 1317662 T3100 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1319114 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1319134 T3063 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> 1319134 T3070 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> 1319134 T3099 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> 1319134 T3083 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> 1319146 T3100 oasc.ZkController.register We are http://127.0.0.1:32371/collection1/ and leader is http://127.0.0.1:32371/collection1/
   [junit4]   2> 1319146 T3100 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32371
   [junit4]   2> 1319146 T3100 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1319147 T3100 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1319147 T3100 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1319149 T3100 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1319150 T3041 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 1319151 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1319151 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 1319441 T3041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1319445 T3041 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51186
   [junit4]   2> 1319445 T3041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1319446 T3041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1319446 T3041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100
   [junit4]   2> 1319447 T3041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/'
   [junit4]   2> 1319488 T3041 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/solr.xml
   [junit4]   2> 1319608 T3041 oasc.CoreContainer.<init> New CoreContainer 434364878
   [junit4]   2> 1319609 T3041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/]
   [junit4]   2> 1319611 T3041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1319612 T3041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1319612 T3041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1319613 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1319613 T3041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1319614 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1319614 T3041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1319615 T3041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1319615 T3041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1319616 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 1319631 T3041 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1319632 T3041 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1319632 T3041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:23478/solr
   [junit4]   2> 1319633 T3041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1319634 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1319637 T3113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4bb2dfbb name:ZooKeeperConnection Watcher:127.0.0.1:23478 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1319638 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1319640 T3041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 1319650 T3041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1319653 T3115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4925b5aa name:ZooKeeperConnection Watcher:127.0.0.1:23478/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1319654 T3041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1319666 T3041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1320646 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1320647 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32371_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:32371"}
   [junit4]   2> 1320679 T3041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51186_
   [junit4]   2> 1320681 T3041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51186_
   [junit4]   2> 1320692 T3063 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> 1320692 T3115 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> 1320692 T3083 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> 1320692 T3070 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> 1320692 T3099 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> 1320701 T3083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1320701 T3099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1320701 T3070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1320701 T3115 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1320702 T3063 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1320702 T3063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1320703 T3083 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1320703 T3099 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1320703 T3070 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1320710 T3116 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1320711 T3116 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1320712 T3116 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1322202 T3064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1322203 T3064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51186_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51186"}
   [junit4]   2> 1322204 T3064 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1322204 T3064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1322222 T3063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1322222 T3115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1322222 T3083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1322222 T3099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1322222 T3070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1322715 T3116 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1322715 T3116 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/collection1
   [junit4]   2> 1322715 T3116 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1322716 T3116 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1322716 T3116 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1322717 T3116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/collection1/'
   [junit4]   2> 1322720 T3116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/collection1/lib/classes/' to classloader
   [junit4]   2> 1322720 T3116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/collection1/lib/README' to classloader
   [junit4]   2> 1322787 T3116 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1322853 T3116 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1322955 T3116 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1322967 T3116 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 1323648 T3116 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1323649 T3116 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1323650 T3116 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1323662 T3116 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1323666 T3116 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1323679 T3116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1323684 T3116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1323688 T3116 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1323689 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1323690 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1323690 T3116 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1323691 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1323691 T3116 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1323692 T3116 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1323692 T3116 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379321804100/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3/
   [junit4]   2> 1323692 T3116 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2c9d964f
   [junit4]   2> 1323694 T3116 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3
   [junit4]   2> 1323694 T3116 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3/index/
   [junit4]   2> 1323694 T3116 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1323695 T3116 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3/index
   [junit4]   2> 1323695 T3116 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=83.4384765625, floorSegmentMB=2.0693359375, forceMergeDeletesPctAllowed=13.50847898249339, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5225840113678659
   [junit4]   2> 1323696 T3116 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d08e1a0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@57581e24),segFN=segments_1,generation=1}
   [junit4]   2> 1323696 T3116 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1323701 T3116 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1323701 T3116 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1323702 T311

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

jetty3/index
   [junit4]   2> 1368487 T3115 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3;done=false>>]
   [junit4]   2> 1368488 T3115 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1379321786460/jetty3
   [junit4]   2> 1368488 T3115 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1368489 T3115 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:184)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:181)
   [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:181)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:392)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:361)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:348)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:95)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:255)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
   [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:129)
   [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> 1368489 T3115 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/90395232597966858-core_node3-n_0000000001
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:152)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:149)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:149)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:258)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
   [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:129)
   [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> 1368490 T3115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1368490 T3115 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1368491 T3115 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1368491 T3115 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> 1368491 T3115 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1368491 T3115 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:235)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
   [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:232)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
   [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:129)
   [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> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=sk, timezone=Canada/Pacific
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=278142920,total=472907776
   [junit4]   2> NOTE: All tests run in this JVM: [TestJoin, TestRecoveryHdfs, AddSchemaFieldsUpdateProcessorFactoryTest, TestReplicationHandler, SpellCheckCollatorTest, SolrRequestParserTest, DocValuesMultiTest, DirectSolrSpellCheckerTest, SliceStateUpdateTest, LeaderElectionIntegrationTest, TestStressRecovery, SolrCmdDistributorTest, ZkSolrClientTest, TestAnalyzedSuggestions, AutoCommitTest, TestCollationField, SolrIndexConfigTest, UniqFieldsUpdateProcessorFactoryTest, TestBinaryField, TestMergePolicyConfig, BJQParserTest, TestNoOpRegenerator, MBeansHandlerTest, OverseerTest, TestFieldTypeResource, CSVRequestHandlerTest, PathHierarchyTokenizerFactoryTest, SoftAutoCommitTest, HdfsCollectionsAPIDistributedZkTest, OpenExchangeRatesOrgProviderTest, TestLuceneMatchVersion, TestStressLucene, TestFastOutputStream, NotRequiredUniqueKeyTest, SolrPluginUtilsTest, UpdateRequestProcessorFactoryTest, TestSolrCoreProperties, HighlighterTest, SolrIndexSplitterTest, StressHdfsTest, TestRTGBase, SOLR749Test, CurrencyFieldOpenExchangeTest, ZkControllerTest, ResponseLogComponentTest, TestCoreContainer, TestNumberUtils, TestSolrQueryParserResource, TestNRTOpen, DistributedQueryElevationComponentTest, LegacyHTMLStripCharFilterTest, TestDistributedGrouping, TestSolrIndexConfig, TestSchemaSimilarityResource, FileBasedSpellCheckerTest, AlternateDirectoryTest, SignatureUpdateProcessorFactoryTest, TestCoreDiscovery, TestSuggestSpellingConverter, TestExtendedDismaxParser, TestFieldCollectionResource, BasicDistributedZkTest, AnalysisAfterCoreReloadTest, SpellPossibilityIteratorTest, ParsingFieldUpdateProcessorsTest, DisMaxRequestHandlerTest, TestAtomicUpdateErrorCases, TestOmitPositions, TestRandomFaceting, InfoHandlerTest, SimplePostToolTest, RequestHandlersTest, TestStressReorder, HardAutoCommitTest, TestAddFieldRealTimeGet, TestMultiCoreConfBootstrap, StatelessScriptUpdateProcessorFactoryTest, TestHashPartitioner, QueryResultKeyTest, ShardSplitTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 67.69s, 1 test, 1 error <<< FAILURES!

[...truncated 508 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:402: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:382: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:455: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1233: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:876: There were test failures: 327 suites, 1453 tests, 1 error, 34 ignored (6 assumptions)

Total time: 57 minutes 55 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