You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/07/26 04:24:17 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk6) - Build # 6655 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6655/
Java: 32bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

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

Error Message:
Server at http://127.0.0.1:55228/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:55228/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([F2B098AF9EE74CDB:735616B7E9B82CE7]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:60)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:37)
	at java.lang.reflect.Method.invoke(Method.java:611)
	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:738)




Build Log:
[...truncated 9322 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 914949 T2853 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 914952 T2853 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1374804513791
   [junit4]   2> 914954 T2853 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 914954 T2854 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 915054 T2853 oasc.ZkTestServer.run start zk server on port:41081
   [junit4]   2> 915056 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 915420 T2860 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42124212 name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 915420 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 915421 T2853 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 915428 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 915430 T2862 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c904c9 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 915431 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 915432 T2853 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 915439 T2853 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 915446 T2853 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 915453 T2853 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 915460 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 915461 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 915472 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 915473 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 915481 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 915482 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 915490 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 915490 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 915498 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 915499 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 915507 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 915508 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 915515 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 915516 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 915523 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 915524 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 915532 T2853 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 915533 T2853 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 915725 T2853 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 915755 T2853 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:४१३८७
   [junit4]   2> 915756 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 915757 T2853 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 915758 T2853 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379
   [junit4]   2> 915759 T2853 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/'
   [junit4]   2> 915771 T2853 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/solr.xml
   [junit4]   2> 915808 T2853 oasc.CoreContainer.<init> New CoreContainer 669067233
   [junit4]   2> 915809 T2853 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/]
   [junit4]   2> 915811 T2853 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 915811 T2853 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 915812 T2853 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 915813 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 915814 T2853 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 915814 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 915815 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 915816 T2853 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 915817 T2853 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 915818 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 915825 T2853 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41081/solr
   [junit4]   2> 915826 T2853 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 915827 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 915830 T2873 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e0c6e0c name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 915833 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 915837 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 915867 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 915870 T2875 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75217521 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 915870 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 915875 T2853 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 915885 T2853 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 915896 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 915902 T2853 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41387_
   [junit4]   2> 915904 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41387_
   [junit4]   2> 915916 T2853 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 915930 T2853 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 915937 T2853 oasc.Overseer.start Overseer (id=90099188616134659-127.0.0.1:41387_-n_0000000000) starting
   [junit4]   2> 915946 T2853 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 915958 T2877 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 915960 T2853 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 915968 T2853 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 915974 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 915985 T2876 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 915992 T2878 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 915992 T2878 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 915994 T2878 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 917501 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 917506 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:41387",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:41387_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 917506 T2876 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 917507 T2876 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 917521 T2875 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> 917995 T2878 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 917996 T2878 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/collection1
   [junit4]   2> 917996 T2878 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 917998 T2878 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 917999 T2878 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 918003 T2878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/collection1/'
   [junit4]   2> 918004 T2878 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/collection1/lib/README' to classloader
   [junit4]   2> 918005 T2878 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/collection1/lib/classes/' to classloader
   [junit4]   2> 918051 T2878 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 918087 T2878 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 918091 T2878 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 918098 T2878 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 918493 T2878 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 918494 T2878 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 918494 T2878 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 918500 T2878 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 918503 T2878 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 918540 T2878 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 918546 T2878 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 918553 T2878 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 918557 T2878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 918557 T2878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 918558 T2878 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 918562 T2878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 918562 T2878 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 918563 T2878 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 918563 T2878 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374804514379/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/control/data/
   [junit4]   2> 918564 T2878 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f0f1f0f
   [junit4]   2> 918576 T2878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/control/data
   [junit4]   2> 918576 T2878 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/control/data/index/
   [junit4]   2> 918577 T2878 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 918578 T2878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/control/data/index
   [junit4]   2> 918581 T2878 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d1e1d1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@55235523),segFN=segments_1,generation=1}
   [junit4]   2> 918581 T2878 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 918587 T2878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 918588 T2878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 918589 T2878 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 918590 T2878 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 918590 T2878 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 918591 T2878 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 918592 T2878 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 918593 T2878 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 918593 T2878 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 918595 T2878 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 918598 T2878 oass.SolrIndexSearcher.<init> Opening Searcher@b5e0b5e main
   [junit4]   2> 918599 T2878 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 918600 T2878 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 918627 T2879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b5e0b5e main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 918629 T2878 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 918629 T2878 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41387 collection:control_collection shard:shard1
   [junit4]   2> 918630 T2878 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 918639 T2878 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 918659 T2878 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 918666 T2878 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 918666 T2878 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 918667 T2878 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41387/collection1/
   [junit4]   2> 918667 T2878 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 918668 T2878 oasc.SyncStrategy.syncToMe http://127.0.0.1:41387/collection1/ has no replicas
   [junit4]   2> 918669 T2878 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41387/collection1/ shard1
   [junit4]   2> 918669 T2878 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 919036 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 919081 T2875 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> 919113 T2878 oasc.ZkController.register We are http://127.0.0.1:41387/collection1/ and leader is http://127.0.0.1:41387/collection1/
   [junit4]   2> 919114 T2878 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41387
   [junit4]   2> 919115 T2878 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 919115 T2878 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 919116 T2878 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 919120 T2878 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 919123 T2853 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 919124 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 919125 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 919131 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 919132 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 919134 T2882 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2c1a2c1a name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 919135 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 919138 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 919145 T2853 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 919316 T2853 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 919318 T2853 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:४६९४३
   [junit4]   2> 919320 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 919320 T2853 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 919321 T2853 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984
   [junit4]   2> 919322 T2853 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/'
   [junit4]   2> 919335 T2853 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/solr.xml
   [junit4]   2> 919373 T2853 oasc.CoreContainer.<init> New CoreContainer 597762977
   [junit4]   2> 919374 T2853 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/]
   [junit4]   2> 919376 T2853 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 919377 T2853 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 919378 T2853 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 919378 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 919379 T2853 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 919380 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 919381 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 919382 T2853 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 919382 T2853 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 919383 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 919391 T2853 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41081/solr
   [junit4]   2> 919392 T2853 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 919393 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 919396 T2893 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23e123e1 name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 919396 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 919401 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 919408 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 919410 T2895 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38713871 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 919411 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 919424 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 920435 T2853 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46943_
   [junit4]   2> 920438 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46943_
   [junit4]   2> 920443 T2875 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> 920447 T2895 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 920448 T2882 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 920453 T2875 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 920490 T2896 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 920491 T2896 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 920493 T2896 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 920601 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 920605 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:41387",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:41387_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 920618 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:46943",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:46943_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 920618 T2876 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 920619 T2876 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 920630 T2882 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> 920630 T2895 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> 920632 T2875 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> 921494 T2896 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 921494 T2896 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/collection1
   [junit4]   2> 921495 T2896 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 921497 T2896 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 921497 T2896 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 921501 T2896 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/collection1/'
   [junit4]   2> 921503 T2896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/collection1/lib/README' to classloader
   [junit4]   2> 921503 T2896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/collection1/lib/classes/' to classloader
   [junit4]   2> 921537 T2896 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 921572 T2896 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 921576 T2896 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 921593 T2896 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 921979 T2896 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 921979 T2896 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 921980 T2896 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 921986 T2896 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 921989 T2896 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 922042 T2896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 922052 T2896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 922061 T2896 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 922069 T2896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 922070 T2896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 922072 T2896 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 922080 T2896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 922081 T2896 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 922082 T2896 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 922083 T2896 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374804517984/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty1/
   [junit4]   2> 922085 T2896 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f0f1f0f
   [junit4]   2> 922087 T2896 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty1
   [junit4]   2> 922088 T2896 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty1/index/
   [junit4]   2> 922090 T2896 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 922091 T2896 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty1/index
   [junit4]   2> 922096 T2896 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e883e88 lockFactory=org.apache.lucene.store.NativeFSLockFactory@65d865d8),segFN=segments_1,generation=1}
   [junit4]   2> 922097 T2896 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 922109 T2896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 922110 T2896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 922111 T2896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 922112 T2896 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 922112 T2896 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 922113 T2896 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 922114 T2896 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 922115 T2896 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 922115 T2896 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 922117 T2896 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 922119 T2896 oass.SolrIndexSearcher.<init> Opening Searcher@7a807a8 main
   [junit4]   2> 922120 T2896 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 922121 T2896 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 922145 T2897 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a807a8 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 922150 T2896 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 922150 T2896 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46943 collection:collection1 shard:shard1
   [junit4]   2> 922151 T2896 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 922184 T2896 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 922208 T2896 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 922215 T2896 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 922216 T2896 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 922216 T2896 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46943/collection1/
   [junit4]   2> 922217 T2896 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 922218 T2896 oasc.SyncStrategy.syncToMe http://127.0.0.1:46943/collection1/ has no replicas
   [junit4]   2> 922218 T2896 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46943/collection1/ shard1
   [junit4]   2> 922219 T2896 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 923660 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 923684 T2882 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> 923685 T2895 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> 923684 T2875 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> 923693 T2896 oasc.ZkController.register We are http://127.0.0.1:46943/collection1/ and leader is http://127.0.0.1:46943/collection1/
   [junit4]   2> 923694 T2896 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46943
   [junit4]   2> 923694 T2896 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 923695 T2896 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 923696 T2896 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 923701 T2896 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 923705 T2853 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 923705 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 923707 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 923899 T2853 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 923901 T2853 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:५५२२८
   [junit4]   2> 923902 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 923903 T2853 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 923904 T2853 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552
   [junit4]   2> 923905 T2853 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/'
   [junit4]   2> 923928 T2853 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/solr.xml
   [junit4]   2> 923966 T2853 oasc.CoreContainer.<init> New CoreContainer 322573114
   [junit4]   2> 923966 T2853 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/]
   [junit4]   2> 923968 T2853 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 923969 T2853 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 923970 T2853 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 923970 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 923971 T2853 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 923972 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 923973 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 923973 T2853 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 923974 T2853 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 923975 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 923983 T2853 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41081/solr
   [junit4]   2> 923984 T2853 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 923986 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 923988 T2909 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f572f57 name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 923989 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 923993 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 924000 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 924003 T2911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21d521d5 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 924003 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 924017 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 925028 T2853 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55228_
   [junit4]   2> 925031 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55228_
   [junit4]   2> 925038 T2895 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> 925038 T2882 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> 925039 T2875 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> 925048 T2895 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 925049 T2882 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 925050 T2911 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 925052 T2875 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 925071 T2912 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 925072 T2912 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 925084 T2912 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 925210 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 925213 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:46943",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:46943_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 925225 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:55228",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:55228_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 925226 T2876 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 925227 T2876 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 925236 T2882 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> 925237 T2911 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> 925237 T2895 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> 925237 T2875 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> 926085 T2912 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 926086 T2912 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/collection1
   [junit4]   2> 926086 T2912 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 926088 T2912 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 926089 T2912 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 926093 T2912 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/collection1/'
   [junit4]   2> 926094 T2912 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/collection1/lib/README' to classloader
   [junit4]   2> 926095 T2912 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/collection1/lib/classes/' to classloader
   [junit4]   2> 926129 T2912 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 926189 T2912 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 926193 T2912 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 926200 T2912 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 926713 T2912 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 926714 T2912 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 926716 T2912 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 926725 T2912 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 926730 T2912 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 926823 T2912 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 926831 T2912 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 926842 T2912 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 926848 T2912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 926849 T2912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 926850 T2912 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 926855 T2912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 926856 T2912 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 926857 T2912 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 926858 T2912 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374804522552/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty2/
   [junit4]   2> 926859 T2912 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f0f1f0f
   [junit4]   2> 926861 T2912 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty2
   [junit4]   2> 926862 T2912 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty2/index/
   [junit4]   2> 926863 T2912 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 926864 T2912 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty2/index
   [junit4]   2> 926867 T2912 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70487048 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3eb83eb8),segFN=segments_1,generation=1}
   [junit4]   2> 926868 T2912 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 926880 T2912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 926881 T2912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 926883 T2912 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 926885 T2912 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 926886 T2912 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 926887 T2912 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 926888 T2912 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 926889 T2912 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 926891 T2912 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 926893 T2912 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 926896 T2912 oass.SolrIndexSearcher.<init> Opening Searcher@1b471b47 main
   [junit4]   2> 926898 T2912 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 926899 T2912 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 926960 T2913 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b471b47 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 926965 T2912 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 926965 T2912 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55228 collection:collection1 shard:shard2
   [junit4]   2> 926966 T2912 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 926982 T2912 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 927015 T2912 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 927027 T2912 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 927028 T2912 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 927047 T2912 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55228/collection1/
   [junit4]   2> 927047 T2912 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 927048 T2912 oasc.SyncStrategy.syncToMe http://127.0.0.1:55228/collection1/ has no replicas
   [junit4]   2> 927049 T2912 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55228/collection1/ shard2
   [junit4]   2> 927050 T2912 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 928292 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 928318 T2895 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> 928319 T2875 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> 928319 T2882 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> 928320 T2911 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> 928380 T2912 oasc.ZkController.register We are http://127.0.0.1:55228/collection1/ and leader is http://127.0.0.1:55228/collection1/
   [junit4]   2> 928381 T2912 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55228
   [junit4]   2> 928382 T2912 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 928383 T2912 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 928384 T2912 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 928390 T2912 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 928394 T2853 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 928395 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 928396 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 928622 T2853 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 928637 T2853 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:३९५२२
   [junit4]   2> 928638 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 928639 T2853 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 928640 T2853 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241
   [junit4]   2> 928640 T2853 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/'
   [junit4]   2> 928653 T2853 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/solr.xml
   [junit4]   2> 928692 T2853 oasc.CoreContainer.<init> New CoreContainer 584458966
   [junit4]   2> 928693 T2853 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/]
   [junit4]   2> 928695 T2853 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 928696 T2853 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 928696 T2853 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 928697 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 928698 T2853 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 928699 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 928700 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 928700 T2853 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 928701 T2853 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 928702 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 928710 T2853 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41081/solr
   [junit4]   2> 928711 T2853 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 928713 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 928717 T2925 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28002800 name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 928717 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 928722 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 928730 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 928732 T2927 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11881188 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 928733 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 928746 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 929765 T2853 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39522_
   [junit4]   2> 929772 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39522_
   [junit4]   2> 929794 T2882 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> 929795 T2875 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> 929795 T2911 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> 929801 T2895 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> 929802 T2927 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 929808 T2882 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 929808 T2875 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 929812 T2911 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 929819 T2895 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 929853 T2928 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 929854 T2928 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 929858 T2928 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 929861 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 929874 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:55228",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:55228_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 929890 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39522",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:39522_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 929891 T2876 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 929892 T2876 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 929905 T2882 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> 929905 T2911 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> 929905 T2875 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> 929909 T2895 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> 929909 T2927 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> 930859 T2928 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 930859 T2928 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/collection1
   [junit4]   2> 930860 T2928 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 930862 T2928 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 930863 T2928 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 930866 T2928 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/collection1/'
   [junit4]   2> 930868 T2928 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/collection1/lib/README' to classloader
   [junit4]   2> 930869 T2928 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/collection1/lib/classes/' to classloader
   [junit4]   2> 930908 T2928 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 930945 T2928 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 930951 T2928 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 930959 T2928 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 931399 T2928 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 931400 T2928 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 931401 T2928 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 931407 T2928 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 931410 T2928 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 931464 T2928 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 931476 T2928 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 931488 T2928 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 931494 T2928 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 931494 T2928 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 931495 T2928 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 931500 T2928 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 931501 T2928 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 931502 T2928 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 931503 T2928 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374804527241/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty3/
   [junit4]   2> 931503 T2928 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f0f1f0f
   [junit4]   2> 931505 T2928 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty3
   [junit4]   2> 931505 T2928 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty3/index/
   [junit4]   2> 931506 T2928 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 931506 T2928 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374804513791/jetty3/index
   [junit4]   2> 931509 T2928 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@24862486 lockFactory=org.apache.lucene.store.NativeFSLockFactory@58d758d7),segFN=segments_1,generation=1}
   [junit4]   2> 931509 T2928 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 931518 T2928 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 931518 T2928 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 931519 T2928 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 931520 T2928 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 931532 T2928 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 931532 T2928 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 931533 T2928 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 931534 T2928 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 931535 T2928 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 931536 T2928 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 931539 T2928 oass.SolrIndexSearcher.<init> Opening Searcher@24272427 main
   [junit4]   2> 931540 T2928 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 931541 T2928 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 931567 T2929 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@24272427 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 931571 T2928 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 931571 T2928 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39522 collection:collection1 shard:shard1
   [junit4]   2> 931572 T2928 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 931586 T2928 oasc.ZkController.register We are http://127.0.0.1:39522/collection1/ and leader is http://127.0.0.1:46943/collection1/
   [junit4]   2> 931587 T2928 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39522
   [junit4]   2> 931587 T2928 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 931588 T2928 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C6206 name=collection1 org.apache.solr.core.SolrCore@4bcd4bcd url=http://127.0.0.1:39522/collection1 node=127.0.0.1:39522_ C6206_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:39522, state=down, node_name=127.0.0.1:39522_, core=collection1}
   [junit4]   2> 931588 T2930 C6206 P39522 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 931589 T2930 C6206 P39522 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 931590 T2930 C6206 P39522 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 931591 T2928 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 931591 T2930 C6206 P39522 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 931595 T2853 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 931596 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 931595 T2930 C6206 P39522 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 931598 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 931605 T2889 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 931801 T2853 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 931803 T2853 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:६०५२४
   [junit4]   2> 931804 T2853 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 931805 T2853 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 931807 T2853 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374804530444
   [junit4]   2> 931808 T2853 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374804530444/'
   [junit4]   2> 931821 T2853 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374804530444/solr.xml
   [junit4]   2> 931858 T2853 oasc.CoreContainer.<init> New CoreContainer 1938322312
   [junit4]   2> 931859 T2853 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374804530444/]
   [junit4]   2> 931861 T2853 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 931862 T2853 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 931863 T2853 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 931863 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 931864 T2853 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 931865 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 931866 T2853 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 931866 T2853 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 931867 T2853 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 931868 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 931876 T2853 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:41081/solr
   [junit4]   2> 931877 T2853 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 931878 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 931880 T2942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71b171b1 name:ZooKeeperConnection Watcher:127.0.0.1:41081 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 931881 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 931885 T2853 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 931892 T2853 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 931894 T2944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67a267a2 name:ZooKeeperConnection Watcher:127.0.0.1:41081/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 931894 T2853 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 931906 T2853 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 932931 T2853 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60524_
   [junit4]   2> 932937 T2853 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60524_
   [junit4]   2> 932946 T2895 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> 932947 T2882 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> 932947 T2875 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> 932948 T2927 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 932950 T2927 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> 932950 T2944 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 932951 T2911 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> 932962 T2895 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 932968 T2882 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 932970 T2911 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 932982 T2876 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 932987 T2876 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39522",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:39522_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 933002 T2882 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> 933003 T2895 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> 933005 T2927 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> 933005 T2944 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> 933010 T2911 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> 933064 T2875 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 933065 T2875 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> 933606 T2889 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node3, state: recovering, che

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

     "node_name":"127.0.0.1:46943_",
   [junit4]   1>            "core":"onenodecollectioncore"}
   [junit4]   1>   /solr/aliases.json (0)
   [junit4]   1>   /solr/live_nodes (5)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:55228_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:39522_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:46943_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:60524_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:41387_ (0)
   [junit4]   1>   /solr/clusterstate.json (0)
   [junit4]   1>   DATA:
   [junit4]   1>       {
   [junit4]   1>         "control_collection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:41387",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:41387_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "onenodecollection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:46943",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:46943_",
   [junit4]   1>                   "roles":"none",
   [junit4]   1>                   "core":"onenodecollectioncore",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "collection1":{
   [junit4]   1>           "shards":{
   [junit4]   1>             "shard1":{
   [junit4]   1>               "range":"80000000-ffffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:46943",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:46943_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:39522",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:39522_",
   [junit4]   1>                   "core":"collection1"}}},
   [junit4]   1>             "shard2":{
   [junit4]   1>               "range":"0-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node2":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:55228",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:55228_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:60524",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:60524_",
   [junit4]   1>                   "core":"collection1"}}}},
   [junit4]   1>           "router":"compositeId"}}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=F2B098AF9EE74CDB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hi_IN -Dtests.timezone=Africa/Gaborone -Dtests.file.encoding=UTF-8
   [junit4] ERROR   35.9s J0 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:55228/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([F2B098AF9EE74CDB:735616B7E9B82CE7]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:738)
   [junit4]   2> 950828 T2853 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 35895 T2852 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> 950897 T2927 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 950898 T2927 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> 950899 T2927 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 952024 T2944 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 952025 T2944 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> 952026 T2944 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=hi_IN, timezone=Africa/Gaborone
   [junit4]   2> NOTE: Linux 3.2.0-49-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=19041856,total=48886272
   [junit4]   2> NOTE: All tests run in this JVM: [HdfsLockFactoryTest, TestUniqueKeyFieldResource, TestSolrQueryParserDefaultOperatorResource, ChaosMonkeyNothingIsSafeTest, BlockDirectoryTest, TestValueSourceCache, SolrInfoMBeanTest, AlternateDirectoryTest, SimpleFacetsTest, TestPerFieldSimilarity, TestSort, TestSchemaResource, SyncSliceTest, PreAnalyzedFieldTest, LoggingHandlerTest, BadCopyFieldTest, TestManagedSchema, BinaryUpdateRequestHandlerTest, SuggesterFSTTest, SchemaVersionSpecificBehaviorTest, TestDocumentBuilder, PreAnalyzedUpdateProcessorTest, HdfsCollectionsAPIDistributedZkTest, TestWriterPerf, TestRandomDVFaceting, ResourceLoaderTest, ShowFileRequestHandlerTest, TestFieldResource, OverseerCollectionProcessorTest, SystemInfoHandlerTest, TestSchemaVersionResource, LukeRequestHandlerTest, RegexBoostProcessorTest, StressHdfsTest, TestReplicationHandler, SearchHandlerTest, TestPropInjectDefaults, MinimalSchemaTest, TestReloadAndDeleteDocs, RAMDirectoryFactoryTest, ReturnFieldsTest, QueryResultKeyTest, SuggesterTest, CircularListTest, MBeansHandlerTest, PrimitiveFieldTypeTest, TestXIncludeConfig, TestPHPSerializedResponseWriter, SpatialFilterTest, TestCollationKeyRangeQueries, QueryEqualityTest, PolyFieldTest, TestSolrCoreProperties, QueryElevationComponentTest, TestPhraseSuggestions, SolrCoreTest, CacheHeaderTest, CoreAdminHandlerTest, PrimUtilsTest, SoftAutoCommitTest, UUIDFieldTest, SliceStateUpdateTest, HdfsChaosMonkeySafeLeaderTest, TestSolrQueryParser, ZkCLITest, FieldMutatingUpdateProcessorTest, DistributedSpellCheckComponentTest, LeaderElectionTest, BadComponentTest, AutoCommitTest, DirectSolrConnectionTest, TestJoin, TestGroupingSearch, SynonymTokenizerTest, TestReversedWildcardFilterFactory, PluginInfoTest, DocValuesTest, DistributedQueryElevationComponentTest, TestDocSet, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test]
   [junit4] Completed on J0 in 37.22s, 1 test, 1 error <<< FAILURES!

[...truncated 501 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:388: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 319 suites, 1345 tests, 1 error, 35 ignored (7 assumptions)

Total time: 53 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure