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/08/29 23:37:45 UTC

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

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7138/
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:57888/_gv/onenodecollectioncore returned non ok status:404, message:Can not find: /_gv/onenodecollectioncore/update

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:57888/_gv/onenodecollectioncore returned non ok status:404, message:Can not find: /_gv/onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([20F457862C87ECDB:A112D99E5BD88CE7]: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 9071 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 136709 T267 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_gv/
   [junit4]   2> 136713 T267 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1377810710430
   [junit4]   2> 136716 T267 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 136717 T268 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 136817 T267 oasc.ZkTestServer.run start zk server on port:38547
   [junit4]   2> 136842 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 136855 T269 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 139020 T274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e9e0e9e name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 139021 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 139023 T267 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 139048 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 139051 T276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4aa34aa3 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 139052 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 139055 T267 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 139126 T267 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 139137 T267 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 139150 T267 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 139168 T267 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> 139170 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 139216 T267 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> 139218 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 139265 T267 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 139267 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 139281 T267 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> 139283 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 139305 T267 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> 139307 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 139317 T267 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> 139319 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 139330 T267 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> 139332 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 139417 T267 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> 139418 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 139432 T267 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> 139433 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 139555 T267 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> 139556 T267 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 139844 T267 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 139848 T267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33438
   [junit4]   2> 139850 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 139852 T267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 139853 T267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284
   [junit4]   2> 139854 T267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/'
   [junit4]   2> 139875 T267 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/solr.xml
   [junit4]   2> 139939 T267 oasc.CoreContainer.<init> New CoreContainer 62129076
   [junit4]   2> 139940 T267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/]
   [junit4]   2> 139942 T267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 139942 T267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 139943 T267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 139944 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 139945 T267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 139946 T267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 139947 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 139947 T267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 139948 T267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 139949 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 139956 T267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 139957 T267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 139959 T267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38547/solr
   [junit4]   2> 139964 T267 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 139965 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 140325 T287 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fcb1fcb name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 140326 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 140341 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 140353 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 140366 T289 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32653265 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 140367 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 140382 T267 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 140397 T267 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 140412 T267 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 140419 T267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33438__gv
   [junit4]   2> 140423 T267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33438__gv
   [junit4]   2> 140486 T267 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 140507 T267 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 140515 T267 oasc.Overseer.start Overseer (id=90296202722476035-127.0.0.1:33438__gv-n_0000000000) starting
   [junit4]   2> 140528 T267 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 140552 T291 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 140553 T267 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 140571 T267 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 140579 T267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 140595 T290 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 140599 T292 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 140599 T292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 140605 T292 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 142118 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 142123 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:33438/_gv",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:33438__gv",
   [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> 142124 T290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 142128 T290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 142150 T289 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> 142606 T292 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 142607 T292 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/collection1
   [junit4]   2> 142608 T292 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 142618 T292 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 142619 T292 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 142625 T292 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/collection1/'
   [junit4]   2> 142627 T292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/collection1/lib/classes/' to classloader
   [junit4]   2> 142628 T292 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/collection1/lib/README' to classloader
   [junit4]   2> 142693 T292 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 142743 T292 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 142748 T292 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 142756 T292 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 143392 T292 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 143393 T292 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 143394 T292 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 143401 T292 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 143406 T292 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 143516 T292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 143525 T292 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 143534 T292 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 143539 T292 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 143540 T292 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 143541 T292 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 143545 T292 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 143546 T292 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 143546 T292 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 143548 T292 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377810713284/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/control/data/
   [junit4]   2> 143548 T292 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24412441
   [junit4]   2> 143550 T292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/control/data
   [junit4]   2> 143550 T292 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/control/data/index/
   [junit4]   2> 143551 T292 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 143551 T292 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/control/data/index
   [junit4]   2> 143552 T292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 143553 T292 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@30e430e4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f491f49),segFN=segments_1,generation=1}
   [junit4]   2> 143554 T292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 143574 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 143575 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 143576 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 143576 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 143577 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 143577 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 143578 T292 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 143579 T292 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 143579 T292 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 143580 T292 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 143581 T292 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 143581 T292 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 143582 T292 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 143583 T292 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 143584 T292 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 143585 T292 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 143589 T292 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 143589 T292 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 143590 T292 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 143591 T292 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@30e430e4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f491f49),segFN=segments_1,generation=1}
   [junit4]   2> 143592 T292 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 143592 T292 oass.SolrIndexSearcher.<init> Opening Searcher@19ab19ab main
   [junit4]   2> 143597 T293 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@19ab19ab main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 143599 T292 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 143599 T292 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33438/_gv collection:control_collection shard:shard1
   [junit4]   2> 143602 T292 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 143610 T292 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 143641 T292 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 143658 T292 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 143659 T292 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 143660 T292 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33438/_gv/collection1/
   [junit4]   2> 143660 T292 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 143661 T292 oasc.SyncStrategy.syncToMe http://127.0.0.1:33438/_gv/collection1/ has no replicas
   [junit4]   2> 143661 T292 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33438/_gv/collection1/ shard1
   [junit4]   2> 143662 T292 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 143674 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 143703 T289 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> 143741 T292 oasc.ZkController.register We are http://127.0.0.1:33438/_gv/collection1/ and leader is http://127.0.0.1:33438/_gv/collection1/
   [junit4]   2> 143742 T292 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33438/_gv
   [junit4]   2> 143759 T292 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 143760 T292 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 143761 T292 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 143835 T292 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 143838 T267 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 143839 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 143847 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 143854 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 143856 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 143860 T296 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77907790 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 143861 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 143864 T267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 143873 T267 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 144151 T267 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 144154 T267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58420
   [junit4]   2> 144156 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 144157 T267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 144159 T267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589
   [junit4]   2> 144160 T267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/'
   [junit4]   2> 144197 T267 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/solr.xml
   [junit4]   2> 144249 T267 oasc.CoreContainer.<init> New CoreContainer 1367232894
   [junit4]   2> 144250 T267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/]
   [junit4]   2> 144251 T267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 144252 T267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 144253 T267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 144254 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 144255 T267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 144255 T267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 144256 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 144257 T267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 144258 T267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 144259 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 144266 T267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 144267 T267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 144269 T267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38547/solr
   [junit4]   2> 144270 T267 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 144271 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 144276 T307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fa00fa0 name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 144277 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 144293 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 144302 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 144308 T309 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a006a0 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 144309 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 144363 T267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 145224 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 145226 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:33438/_gv",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:33438__gv",
   [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> 145238 T289 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> 145238 T296 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> 145238 T309 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> 145375 T267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58420__gv
   [junit4]   2> 145377 T267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58420__gv
   [junit4]   2> 145387 T296 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145387 T289 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145387 T296 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> 145388 T289 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> 145390 T309 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 145391 T309 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> 145414 T310 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 145414 T310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 145421 T310 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 146826 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 146829 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58420/_gv",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:58420__gv",
   [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> 146829 T290 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 146830 T290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 146846 T289 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> 146846 T309 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> 146847 T296 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> 147422 T310 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 147423 T310 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/collection1
   [junit4]   2> 147424 T310 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 147426 T310 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 147427 T310 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 147431 T310 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/collection1/'
   [junit4]   2> 147434 T310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/collection1/lib/classes/' to classloader
   [junit4]   2> 147435 T310 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/collection1/lib/README' to classloader
   [junit4]   2> 147494 T310 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 147543 T310 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 147550 T310 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 147560 T310 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 148049 T310 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 148050 T310 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 148051 T310 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 148065 T310 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 148068 T310 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 148106 T310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 148113 T310 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 148121 T310 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 148126 T310 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 148127 T310 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 148127 T310 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 148140 T310 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 148141 T310 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 148142 T310 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 148142 T310 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377810717589/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty1/
   [junit4]   2> 148143 T310 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24412441
   [junit4]   2> 148144 T310 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty1
   [junit4]   2> 148145 T310 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty1/index/
   [junit4]   2> 148145 T310 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 148146 T310 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty1/index
   [junit4]   2> 148147 T310 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 148148 T310 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5eee5eee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@764e764e),segFN=segments_1,generation=1}
   [junit4]   2> 148148 T310 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 148156 T310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 148157 T310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 148158 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 148158 T310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 148159 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 148160 T310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 148160 T310 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 148161 T310 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 148161 T310 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 148162 T310 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 148163 T310 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 148164 T310 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 148165 T310 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 148166 T310 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 148166 T310 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 148168 T310 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 148171 T310 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 148172 T310 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 148173 T310 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 148174 T310 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5eee5eee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@764e764e),segFN=segments_1,generation=1}
   [junit4]   2> 148175 T310 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 148175 T310 oass.SolrIndexSearcher.<init> Opening Searcher@48984898 main
   [junit4]   2> 148182 T311 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48984898 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 148186 T310 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 148186 T310 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58420/_gv collection:collection1 shard:shard1
   [junit4]   2> 148187 T310 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 148195 T310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 148293 T310 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 148316 T310 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 148317 T310 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 148317 T310 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58420/_gv/collection1/
   [junit4]   2> 148318 T310 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 148318 T310 oasc.SyncStrategy.syncToMe http://127.0.0.1:58420/_gv/collection1/ has no replicas
   [junit4]   2> 148319 T310 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58420/_gv/collection1/ shard1
   [junit4]   2> 148319 T310 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 148368 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 148400 T296 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> 148401 T309 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> 148401 T289 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> 148451 T310 oasc.ZkController.register We are http://127.0.0.1:58420/_gv/collection1/ and leader is http://127.0.0.1:58420/_gv/collection1/
   [junit4]   2> 148452 T310 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58420/_gv
   [junit4]   2> 148452 T310 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 148453 T310 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 148453 T310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 148459 T310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 148463 T267 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 148465 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 148466 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 148738 T267 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 148741 T267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57888
   [junit4]   2> 148742 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 148743 T267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 148744 T267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191
   [junit4]   2> 148745 T267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/'
   [junit4]   2> 148757 T267 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/solr.xml
   [junit4]   2> 148793 T267 oasc.CoreContainer.<init> New CoreContainer 267718645
   [junit4]   2> 148794 T267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/]
   [junit4]   2> 148796 T267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 148796 T267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 148797 T267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 148798 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 148799 T267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 148799 T267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 148800 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 148801 T267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 148802 T267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 148803 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 148809 T267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 148816 T267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 148818 T267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38547/solr
   [junit4]   2> 148819 T267 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 148821 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 148825 T323 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7fd97fd9 name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 148826 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 148830 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 148855 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 148857 T325 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@381f381f name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 148858 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 148872 T267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 149884 T267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57888__gv
   [junit4]   2> 149887 T267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57888__gv
   [junit4]   2> 149947 T325 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 149948 T309 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 149950 T296 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 149950 T309 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> 149950 T296 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> 149953 T289 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 149955 T289 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> 149967 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 149972 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58420/_gv",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:58420__gv",
   [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> 150023 T326 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 150023 T326 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 150028 T326 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 150029 T309 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> 150029 T296 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> 150029 T325 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> 150051 T289 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> 151557 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 151561 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57888/_gv",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:57888__gv",
   [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> 151561 T290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 151562 T290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 151579 T309 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> 151579 T289 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> 151580 T325 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> 151579 T296 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> 152029 T326 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 152030 T326 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/collection1
   [junit4]   2> 152031 T326 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 152034 T326 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 152035 T326 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 152040 T326 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/collection1/'
   [junit4]   2> 152042 T326 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/collection1/lib/classes/' to classloader
   [junit4]   2> 152043 T326 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/collection1/lib/README' to classloader
   [junit4]   2> 152091 T326 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 152143 T326 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 152147 T326 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 152156 T326 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 152648 T326 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 152649 T326 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 152650 T326 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 152656 T326 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 152659 T326 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 152704 T326 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 152720 T326 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 152728 T326 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 152731 T326 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 152732 T326 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 152733 T326 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 152738 T326 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 152739 T326 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 152739 T326 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 152740 T326 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377810722191/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty2/
   [junit4]   2> 152741 T326 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24412441
   [junit4]   2> 152742 T326 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty2
   [junit4]   2> 152743 T326 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty2/index/
   [junit4]   2> 152743 T326 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 152744 T326 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty2/index
   [junit4]   2> 152745 T326 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 152746 T326 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71727172 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3f903f90),segFN=segments_1,generation=1}
   [junit4]   2> 152747 T326 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 152756 T326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 152757 T326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 152757 T326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 152758 T326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 152758 T326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 152759 T326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 152760 T326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 152760 T326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 152761 T326 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 152762 T326 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 152763 T326 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 152764 T326 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 152765 T326 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 152766 T326 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 152767 T326 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 152770 T326 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 152774 T326 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 152775 T326 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 152776 T326 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 152777 T326 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@71727172 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3f903f90),segFN=segments_1,generation=1}
   [junit4]   2> 152777 T326 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 152778 T326 oass.SolrIndexSearcher.<init> Opening Searcher@1ab11ab1 main
   [junit4]   2> 152785 T327 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ab11ab1 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 152789 T326 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 152790 T326 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57888/_gv collection:collection1 shard:shard2
   [junit4]   2> 152791 T326 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 152800 T326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 152834 T326 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 152843 T326 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 152844 T326 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 152844 T326 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57888/_gv/collection1/
   [junit4]   2> 152845 T326 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 152845 T326 oasc.SyncStrategy.syncToMe http://127.0.0.1:57888/_gv/collection1/ has no replicas
   [junit4]   2> 152846 T326 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57888/_gv/collection1/ shard2
   [junit4]   2> 152846 T326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 153136 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 153170 T289 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> 153171 T296 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> 153171 T325 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> 153171 T309 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> 153220 T326 oasc.ZkController.register We are http://127.0.0.1:57888/_gv/collection1/ and leader is http://127.0.0.1:57888/_gv/collection1/
   [junit4]   2> 153220 T326 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57888/_gv
   [junit4]   2> 153221 T326 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 153222 T326 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 153222 T326 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 153227 T326 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 153230 T267 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 153231 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 153232 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 153536 T267 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 153539 T267 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45134
   [junit4]   2> 153541 T267 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 153542 T267 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 153544 T267 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954
   [junit4]   2> 153545 T267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/'
   [junit4]   2> 153575 T267 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/solr.xml
   [junit4]   2> 153625 T267 oasc.CoreContainer.<init> New CoreContainer 338695216
   [junit4]   2> 153626 T267 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/]
   [junit4]   2> 153628 T267 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 153629 T267 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 153630 T267 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 153631 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 153631 T267 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 153632 T267 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 153633 T267 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 153634 T267 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 153635 T267 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 153636 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 153643 T267 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 153644 T267 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 153646 T267 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38547/solr
   [junit4]   2> 153647 T267 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 153648 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 153665 T339 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14a314a3 name:ZooKeeperConnection Watcher:127.0.0.1:38547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 153666 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 153671 T267 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 153686 T267 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 153689 T341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e316e31 name:ZooKeeperConnection Watcher:127.0.0.1:38547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 153690 T267 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 153711 T267 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 154702 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 154704 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57888/_gv",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:57888__gv",
   [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> 154719 T289 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> 154719 T309 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> 154720 T341 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> 154719 T296 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> 154719 T325 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> 154747 T267 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45134__gv
   [junit4]   2> 154752 T267 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45134__gv
   [junit4]   2> 154763 T296 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 154764 T296 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> 154765 T325 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 154765 T325 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> 154767 T289 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 154767 T289 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> 154770 T309 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 154771 T309 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> 154773 T341 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 154773 T341 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> 154838 T342 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 154838 T342 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 154841 T342 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 156264 T290 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 156267 T290 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45134/_gv",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:45134__gv",
   [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> 156267 T290 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 156268 T290 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 156281 T289 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> 156281 T341 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> 156282 T309 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> 156281 T296 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> 156282 T325 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> 156842 T342 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 156843 T342 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/collection1
   [junit4]   2> 156843 T342 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 156846 T342 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 156846 T342 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 156851 T342 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/collection1/'
   [junit4]   2> 156853 T342 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/collection1/lib/classes/' to classloader
   [junit4]   2> 156854 T342 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/collection1/lib/README' to classloader
   [junit4]   2> 156915 T342 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 156953 T342 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 156957 T342 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 156965 T342 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 157413 T342 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 157413 T342 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 157414 T342 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 157422 T342 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 157426 T342 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 157483 T342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 157491 T342 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 157504 T342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 157509 T342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 157510 T342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 157511 T342 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 157517 T342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 157518 T342 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 157519 T342 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 157520 T342 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377810726954/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty3/
   [junit4]   2> 157521 T342 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@24412441
   [junit4]   2> 157523 T342 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty3
   [junit4]   2> 157524 T342 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty3/index/
   [junit4]   2> 157525 T342 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 157526 T342 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377810710430/jetty3/index
   [junit4]   2> 157527 T342 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 157528 T342 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a880a88 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4c1a4c1a),segFN=segments_1,generation=1}
   [junit4]   2> 157529 T342 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 157538 T342 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 157539 T342 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 157540 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 157540 T342 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 157541 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 157542 T342 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 157543 T342 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 157543 T342 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 157544 T342 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 157545 T342 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 157546 T342 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 157546 T342 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 157547 T342 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 157548 T342 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 157549 T342 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 157550 T342 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 157554 T342 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 157554 T342 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 157556 T342 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=17, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 157557 T342 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a880a88 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4c1a4c1a),segFN=segments_1,generation=1}
   [junit4]   2> 157557 T342 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 157558 T342 oass.SolrIndexSearcher.<init> Opening Searcher@7ea47ea4 main
   [junit4]   2> 157566 T343 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ea47ea4 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   

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

s/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:58420/_gv",
   [junit4]   1>            "node_name":"127.0.0.1:58420__gv",
   [junit4]   1>            "core":"collection1"}
   [junit4]   1>      /solr/collections/collection1/leaders/shard2 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:57888/_gv",
   [junit4]   1>            "node_name":"127.0.0.1:57888__gv",
   [junit4]   1>            "core":"collection1"}
   [junit4]   1>     /solr/collections/collection1/shards (0)
   [junit4]   1>    /solr/collections/onenodecollection (2)
   [junit4]   1>    DATA:
   [junit4]   1>        {
   [junit4]   1>          "router":"compositeId",
   [junit4]   1>          "configName":"conf1"}
   [junit4]   1>     /solr/collections/onenodecollection/leader_elect (1)
   [junit4]   1>      /solr/collections/onenodecollection/leader_elect/shard1 (1)
   [junit4]   1>       /solr/collections/onenodecollection/leader_elect/shard1/election (1)
   [junit4]   1>        /solr/collections/onenodecollection/leader_elect/shard1/election/90296202722476038-core_node1-n_0000000000 (0)
   [junit4]   1>     /solr/collections/onenodecollection/leaders (1)
   [junit4]   1>      /solr/collections/onenodecollection/leaders/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:58420/_gv",
   [junit4]   1>            "node_name":"127.0.0.1:58420__gv",
   [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:57888__gv (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:58420__gv (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:45134__gv (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:33438__gv (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:36693__gv (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:33438/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:33438__gv",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"},
   [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:58420/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:58420__gv",
   [junit4]   1>                   "roles":"none",
   [junit4]   1>                   "core":"onenodecollectioncore",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"},
   [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:58420/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:58420__gv",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:45134/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:45134__gv",
   [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:57888/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:57888__gv",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:36693/_gv",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:36693__gv",
   [junit4]   1>                   "core":"collection1"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"}}
   [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=20F457862C87ECDB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=no -Dtests.timezone=Pacific/Guadalcanal -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   39.0s J1 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:57888/_gv/onenodecollectioncore returned non ok status:404, message:Can not find: /_gv/onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([20F457862C87ECDB:A112D99E5BD88CE7]: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> 175718 T267 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 39028 T266 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> 176529 T358 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 176530 T358 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene45: {}, docValues:{}, sim=DefaultSimilarity, locale=no, timezone=Pacific/Guadalcanal
   [junit4]   2> NOTE: Linux 3.2.0-52-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=7791968,total=42411520
   [junit4]   2> NOTE: All tests run in this JVM: [XmlUpdateRequestHandlerTest, ConvertedLegacyTest, HdfsUnloadDistributedZkTest, TestUpdate, PingRequestHandlerTest, DirectUpdateHandlerTest, AlternateDirectoryTest, TestSolrQueryParserResource, TestShardHandlerFactory, XsltUpdateRequestHandlerTest, TestJmxIntegration, DistanceFunctionTest, TestIndexingPerformance, TestCollationKeyRangeQueries, TestDFRSimilarityFactory, DocumentAnalysisRequestHandlerTest, TestRecovery, MinimalSchemaTest, TestNumberUtils, SolrCoreCheckLockOnStartupTest, TestStressLucene, TestFuzzyAnalyzedSuggestions, TestDefaultSearchFieldResource, PathHierarchyTokenizerFactoryTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 40.07s, 1 test, 1 error <<< FAILURES!

[...truncated 857 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:450: 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: 325 suites, 1414 tests, 1 error, 35 ignored (6 assumptions)

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