lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build # 7364 - Failure!
Date Sat, 07 Sep 2013 22:16:09 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7364/
Java: 32bit/ibm-j9-jdk7 -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:56444/vh_ydi/p/onenodecollectioncore returned non ok status:404, message:Can not find: /vh_ydi/p/onenodecollectioncore/update

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:56444/vh_ydi/p/onenodecollectioncore returned non ok status:404, message:Can not find: /vh_ydi/p/onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([87D988849DFD93E9:63F069CEAA2F3D5]: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:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	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:780)




Build Log:
[...truncated 9958 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 646129 T1588 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vh_ydi/p
   [junit4]   2> 646134 T1588 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1378591451754
   [junit4]   2> 646135 T1588 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 646136 T1589 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 646236 T1588 oasc.ZkTestServer.run start zk server on port:52694
   [junit4]   2> 646243 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646280 T1595 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3481383a name:ZooKeeperConnection Watcher:127.0.0.1:52694 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646281 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 646282 T1588 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 646292 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646294 T1597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c27ece0c name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646295 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 646296 T1588 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 646302 T1588 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 646308 T1588 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 646312 T1588 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 646317 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 646319 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 646327 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 646328 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 646335 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 646336 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 646342 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 646344 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 646349 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 646351 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 646356 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 646357 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 646363 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 646365 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 646370 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 646371 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 646377 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 646378 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 646384 T1588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 646385 T1588 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 646474 T1588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 646481 T1588 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48632
   [junit4]   2> 646482 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 646483 T1588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 646483 T1588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011
   [junit4]   2> 646484 T1588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/'
   [junit4]   2> 646492 T1588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/solr.xml
   [junit4]   2> 646524 T1588 oasc.CoreContainer.<init> New CoreContainer -945026393
   [junit4]   2> 646525 T1588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/]
   [junit4]   2> 646527 T1588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 646527 T1588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 646528 T1588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 646528 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 646529 T1588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 646530 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 646530 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 646531 T1588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 646532 T1588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 646532 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 646538 T1588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 646538 T1588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 646539 T1588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52694/solr
   [junit4]   2> 646540 T1588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 646543 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646544 T1608 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5d3bf00 name:ZooKeeperConnection Watcher:127.0.0.1:52694 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646545 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 646547 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 646553 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646554 T1610 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4be8a548 name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646554 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 646558 T1588 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 646562 T1588 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 646566 T1588 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 646568 T1588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48632_vh_ydi%2Fp
   [junit4]   2> 646569 T1588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48632_vh_ydi%2Fp
   [junit4]   2> 646573 T1588 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 646584 T1588 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 646590 T1588 oasc.Overseer.start Overseer (id=90347369382412291-127.0.0.1:48632_vh_ydi%2Fp-n_0000000000) starting
   [junit4]   2> 646596 T1588 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 646604 T1612 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 646604 T1588 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 646609 T1588 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 646613 T1588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 646619 T1611 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 646624 T1613 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 646625 T1613 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 646627 T1613 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 648125 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 648127 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48632/vh_ydi/p",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:48632_vh_ydi%2Fp",
   [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> 648128 T1611 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 648128 T1611 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 648135 T1610 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> 648628 T1613 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 648629 T1613 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/collection1
   [junit4]   2> 648630 T1613 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 648632 T1613 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 648632 T1613 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 648635 T1613 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/collection1/'
   [junit4]   2> 648637 T1613 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/collection1/lib/classes/' to classloader
   [junit4]   2> 648638 T1613 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/collection1/lib/README' to classloader
   [junit4]   2> 648679 T1613 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 648713 T1613 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 648715 T1613 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 648721 T1613 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 649083 T1613 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 649093 T1613 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 649098 T1613 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 649115 T1613 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 649121 T1613 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 649131 T1613 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 649132 T1613 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 649133 T1613 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 649133 T1613 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 649135 T1613 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 649135 T1613 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 649136 T1613 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 649136 T1613 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1378591452011/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/control/data/
   [junit4]   2> 649136 T1613 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ecc0a16e
   [junit4]   2> 649139 T1613 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/control/data
   [junit4]   2> 649139 T1613 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/control/data/index/
   [junit4]   2> 649140 T1613 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 649141 T1613 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/control/data/index
   [junit4]   2> 649142 T1613 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 649145 T1613 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bfb259d3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cdaa976),segFN=segments_1,generation=1}
   [junit4]   2> 649145 T1613 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 649149 T1613 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 649149 T1613 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 649150 T1613 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 649151 T1613 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 649151 T1613 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 649152 T1613 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 649153 T1613 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 649153 T1613 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 649154 T1613 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 649155 T1613 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 649155 T1613 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 649156 T1613 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 649156 T1613 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 649157 T1613 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 649158 T1613 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 649160 T1613 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 649164 T1613 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 649165 T1613 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 649166 T1613 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 649168 T1613 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bfb259d3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@cdaa976),segFN=segments_1,generation=1}
   [junit4]   2> 649169 T1613 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 649169 T1613 oass.SolrIndexSearcher.<init> Opening Searcher@7056786 main
   [junit4]   2> 649172 T1614 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7056786 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 649173 T1613 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 649173 T1613 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48632/vh_ydi/p collection:control_collection shard:shard1
   [junit4]   2> 649174 T1613 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 649181 T1613 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 649197 T1613 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 649201 T1613 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 649201 T1613 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 649202 T1613 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48632/vh_ydi/p/collection1/
   [junit4]   2> 649202 T1613 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 649203 T1613 oasc.SyncStrategy.syncToMe http://127.0.0.1:48632/vh_ydi/p/collection1/ has no replicas
   [junit4]   2> 649204 T1613 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48632/vh_ydi/p/collection1/ shard1
   [junit4]   2> 649205 T1613 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 649639 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 649646 T1610 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> 649662 T1613 oasc.ZkController.register We are http://127.0.0.1:48632/vh_ydi/p/collection1/ and leader is http://127.0.0.1:48632/vh_ydi/p/collection1/
   [junit4]   2> 649663 T1613 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48632/vh_ydi/p
   [junit4]   2> 649663 T1613 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 649664 T1613 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 649664 T1613 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 649666 T1613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 649667 T1588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 649668 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 649669 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 649676 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 649681 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649682 T1617 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7376cb1a name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649682 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649684 T1588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 649686 T1588 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 649758 T1588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 649765 T1588 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36564
   [junit4]   2> 649766 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 649767 T1588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 649767 T1588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306
   [junit4]   2> 649768 T1588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/'
   [junit4]   2> 649776 T1588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/solr.xml
   [junit4]   2> 649816 T1588 oasc.CoreContainer.<init> New CoreContainer 2088308207
   [junit4]   2> 649817 T1588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/]
   [junit4]   2> 649818 T1588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 649819 T1588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 649819 T1588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 649820 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 649821 T1588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 649821 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 649822 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 649822 T1588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 649823 T1588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 649824 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 649828 T1588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 649829 T1588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 649830 T1588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52694/solr
   [junit4]   2> 649830 T1588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 649833 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649834 T1628 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c8c9568f name:ZooKeeperConnection Watcher:127.0.0.1:52694 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649834 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649836 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 649842 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 649843 T1630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@336b44de name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 649844 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 649847 T1588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 650851 T1588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36564_vh_ydi%2Fp
   [junit4]   2> 650853 T1588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36564_vh_ydi%2Fp
   [junit4]   2> 650858 T1610 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 650858 T1617 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 650858 T1630 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 650859 T1610 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> 650869 T1631 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 650870 T1631 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 650872 T1631 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 651153 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 651155 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48632/vh_ydi/p",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:48632_vh_ydi%2Fp",
   [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> 651160 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36564/vh_ydi/p",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:36564_vh_ydi%2Fp",
   [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> 651161 T1611 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 651162 T1611 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 651168 T1610 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> 651168 T1630 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> 651168 T1617 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> 651873 T1631 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 651874 T1631 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/collection1
   [junit4]   2> 651875 T1631 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 651876 T1631 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 651877 T1631 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 651879 T1631 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/collection1/'
   [junit4]   2> 651881 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/collection1/lib/classes/' to classloader
   [junit4]   2> 651882 T1631 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/collection1/lib/README' to classloader
   [junit4]   2> 651928 T1631 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 651963 T1631 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 651964 T1631 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 651971 T1631 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 652309 T1631 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 652315 T1631 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 652317 T1631 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 652330 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 652334 T1631 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 652338 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 652340 T1631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 652340 T1631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 652340 T1631 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 652341 T1631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 652342 T1631 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 652342 T1631 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 652343 T1631 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1378591455306/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty1/
   [junit4]   2> 652343 T1631 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ecc0a16e
   [junit4]   2> 652344 T1631 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty1
   [junit4]   2> 652345 T1631 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty1/index/
   [junit4]   2> 652345 T1631 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 652346 T1631 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty1/index
   [junit4]   2> 652346 T1631 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 652347 T1631 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3b3289e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@902cdc03),segFN=segments_1,generation=1}
   [junit4]   2> 652347 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 652350 T1631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 652350 T1631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 652351 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 652351 T1631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 652352 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 652352 T1631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 652352 T1631 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 652353 T1631 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 652353 T1631 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 652354 T1631 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 652354 T1631 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 652355 T1631 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 652355 T1631 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 652356 T1631 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 652356 T1631 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 652357 T1631 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 652360 T1631 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 652361 T1631 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 652361 T1631 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 652362 T1631 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3b3289e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@902cdc03),segFN=segments_1,generation=1}
   [junit4]   2> 652362 T1631 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 652363 T1631 oass.SolrIndexSearcher.<init> Opening Searcher@fb0f52b6 main
   [junit4]   2> 652366 T1632 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@fb0f52b6 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 652367 T1631 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 652367 T1631 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36564/vh_ydi/p collection:collection1 shard:shard1
   [junit4]   2> 652368 T1631 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 652372 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 652382 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 652385 T1631 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 652386 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 652386 T1631 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36564/vh_ydi/p/collection1/
   [junit4]   2> 652386 T1631 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 652387 T1631 oasc.SyncStrategy.syncToMe http://127.0.0.1:36564/vh_ydi/p/collection1/ has no replicas
   [junit4]   2> 652387 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36564/vh_ydi/p/collection1/ shard1
   [junit4]   2> 652388 T1631 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 652678 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 652690 T1610 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> 652690 T1617 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> 652690 T1630 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> 652695 T1631 oasc.ZkController.register We are http://127.0.0.1:36564/vh_ydi/p/collection1/ and leader is http://127.0.0.1:36564/vh_ydi/p/collection1/
   [junit4]   2> 652696 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36564/vh_ydi/p
   [junit4]   2> 652696 T1631 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 652697 T1631 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 652698 T1631 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 652701 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 652703 T1588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 652704 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 652706 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 652783 T1588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 652790 T1588 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56444
   [junit4]   2> 652791 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 652791 T1588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 652792 T1588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335
   [junit4]   2> 652793 T1588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/'
   [junit4]   2> 652801 T1588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/solr.xml
   [junit4]   2> 652832 T1588 oasc.CoreContainer.<init> New CoreContainer 2109737805
   [junit4]   2> 652833 T1588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/]
   [junit4]   2> 652834 T1588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 652834 T1588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 652835 T1588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 652836 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 652836 T1588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 652837 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 652837 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 652838 T1588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 652839 T1588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 652839 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 652844 T1588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 652845 T1588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 652846 T1588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52694/solr
   [junit4]   2> 652846 T1588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 652850 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652851 T1644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b433985f name:ZooKeeperConnection Watcher:127.0.0.1:52694 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652852 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652854 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 652861 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 652863 T1646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b221fbd5 name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 652864 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 652870 T1588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 653875 T1588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56444_vh_ydi%2Fp
   [junit4]   2> 653878 T1588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56444_vh_ydi%2Fp
   [junit4]   2> 653884 T1630 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 653884 T1610 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 653884 T1617 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 653885 T1630 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> 653885 T1610 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> 653884 T1646 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 653886 T1617 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> 653895 T1647 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 653896 T1647 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 653898 T1647 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 654201 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 654202 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36564/vh_ydi/p",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:36564_vh_ydi%2Fp",
   [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> 654209 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:56444/vh_ydi/p",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:56444_vh_ydi%2Fp",
   [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> 654210 T1611 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 654211 T1611 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 654216 T1630 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> 654216 T1610 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> 654216 T1617 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> 654216 T1646 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> 654899 T1647 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 654900 T1647 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/collection1
   [junit4]   2> 654901 T1647 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 654902 T1647 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 654903 T1647 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 654905 T1647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/collection1/'
   [junit4]   2> 654907 T1647 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/collection1/lib/classes/' to classloader
   [junit4]   2> 654908 T1647 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/collection1/lib/README' to classloader
   [junit4]   2> 654967 T1647 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 655002 T1647 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 655003 T1647 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 655010 T1647 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 655351 T1647 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 655356 T1647 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 655359 T1647 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 655371 T1647 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655376 T1647 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655381 T1647 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655383 T1647 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655383 T1647 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655384 T1647 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655386 T1647 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655386 T1647 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655387 T1647 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 655387 T1647 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1378591458335/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty2/
   [junit4]   2> 655388 T1647 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ecc0a16e
   [junit4]   2> 655389 T1647 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty2
   [junit4]   2> 655390 T1647 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty2/index/
   [junit4]   2> 655390 T1647 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 655391 T1647 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty2/index
   [junit4]   2> 655392 T1647 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655393 T1647 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@29702a63 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3830968c),segFN=segments_1,generation=1}
   [junit4]   2> 655394 T1647 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655397 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 655398 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 655399 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 655399 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655400 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655400 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 655401 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655402 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655402 T1647 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 655403 T1647 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 655404 T1647 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 655404 T1647 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 655405 T1647 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 655406 T1647 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 655407 T1647 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 655408 T1647 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 655412 T1647 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 655413 T1647 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 655414 T1647 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655415 T1647 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@29702a63 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3830968c),segFN=segments_1,generation=1}
   [junit4]   2> 655415 T1647 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655416 T1647 oass.SolrIndexSearcher.<init> Opening Searcher@a11f9e1a main
   [junit4]   2> 655419 T1648 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a11f9e1a main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 655421 T1647 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 655422 T1647 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56444/vh_ydi/p collection:collection1 shard:shard2
   [junit4]   2> 655422 T1647 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 655427 T1647 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 655437 T1647 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 655443 T1647 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 655444 T1647 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 655444 T1647 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56444/vh_ydi/p/collection1/
   [junit4]   2> 655444 T1647 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 655445 T1647 oasc.SyncStrategy.syncToMe http://127.0.0.1:56444/vh_ydi/p/collection1/ has no replicas
   [junit4]   2> 655445 T1647 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56444/vh_ydi/p/collection1/ shard2
   [junit4]   2> 655445 T1647 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 655727 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 655742 T1610 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> 655742 T1630 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> 655742 T1646 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> 655742 T1617 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> 655754 T1647 oasc.ZkController.register We are http://127.0.0.1:56444/vh_ydi/p/collection1/ and leader is http://127.0.0.1:56444/vh_ydi/p/collection1/
   [junit4]   2> 655755 T1647 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56444/vh_ydi/p
   [junit4]   2> 655756 T1647 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 655756 T1647 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 655757 T1647 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 655760 T1647 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 655763 T1588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 655764 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 655766 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 655854 T1588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 655858 T1588 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33466
   [junit4]   2> 655859 T1588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 655860 T1588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 655861 T1588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396
   [junit4]   2> 655861 T1588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/'
   [junit4]   2> 655871 T1588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/solr.xml
   [junit4]   2> 655905 T1588 oasc.CoreContainer.<init> New CoreContainer 1003096871
   [junit4]   2> 655906 T1588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/]
   [junit4]   2> 655907 T1588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 655908 T1588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 655908 T1588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 655909 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 655910 T1588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 655911 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 655911 T1588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 655912 T1588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 655913 T1588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 655913 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 655918 T1588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 655918 T1588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 655919 T1588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52694/solr
   [junit4]   2> 655920 T1588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 655923 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 655924 T1660 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@486432fe name:ZooKeeperConnection Watcher:127.0.0.1:52694 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 655924 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 655926 T1588 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 655934 T1588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 655936 T1662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@fdcc0311 name:ZooKeeperConnection Watcher:127.0.0.1:52694/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 655936 T1588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 655940 T1588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 656942 T1588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33466_vh_ydi%2Fp
   [junit4]   2> 656944 T1588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33466_vh_ydi%2Fp
   [junit4]   2> 656946 T1646 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> 656947 T1617 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 656947 T1610 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 656947 T1617 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> 656947 T1662 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 656948 T1610 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> 656948 T1630 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 656949 T1630 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> 656949 T1646 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 656956 T1663 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 656956 T1663 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 656957 T1663 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 657251 T1611 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 657252 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:56444/vh_ydi/p",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:56444_vh_ydi%2Fp",
   [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> 657255 T1611 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:33466/vh_ydi/p",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:33466_vh_ydi%2Fp",
   [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> 657256 T1611 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 657256 T1611 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 657322 T1662 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> 657322 T1646 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> 657322 T1610 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> 657322 T1630 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> 657322 T1617 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> 657957 T1663 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 657958 T1663 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/collection1
   [junit4]   2> 657959 T1663 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 657960 T1663 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 657960 T1663 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 657962 T1663 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/collection1/'
   [junit4]   2> 657963 T1663 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/collection1/lib/classes/' to classloader
   [junit4]   2> 657964 T1663 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/collection1/lib/README' to classloader
   [junit4]   2> 658003 T1663 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 658056 T1663 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 658058 T1663 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 658068 T1663 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 658440 T1663 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 658445 T1663 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 658448 T1663 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 658459 T1663 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 658465 T1663 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 658471 T1663 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 658473 T1663 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 658473 T1663 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 658474 T1663 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 658475 T1663 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 658475 T1663 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 658476 T1663 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 658477 T1663 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1378591461396/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty3/
   [junit4]   2> 658477 T1663 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ecc0a16e
   [junit4]   2> 658479 T1663 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty3
   [junit4]   2> 658480 T1663 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty3/index/
   [junit4]   2> 658480 T1663 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 658481 T1663 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1378591451754/jetty3/index
   [junit4]   2> 658481 T1663 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 658482 T1663 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8eecb1a2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71684d86),segFN=segments_1,generation=1}
   [junit4]   2> 658482 T1663 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 658485 T1663 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 658485 T1663 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 658485 T1663 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 658486 T1663 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 658486 T1663 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 658487 T1663 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 658487 T1663 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 658488 T1663 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 658488 T1663 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 658488 T1663 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 658489 T1663 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 658489 T1663 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 658490 T1663 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 658490 T1663 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 658491 T1663 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 658492 T1663 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 658495 T1663 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 658496 T1663 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 658497 T1663 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 658498 T1663 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8eecb1a2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@71684d86),segFN=segments_1,generation=1}
   [junit4]   2> 658498 T1663 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 658499 T1663 oass.SolrIndexSearcher.<init> Opening Searcher@343b1cb8 main
   [junit4]   2> 658502 T1664 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@343b1cb8 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 658504 T1663 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 658504 T1663 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33466/vh_ydi/p collection:collection1 shard:shard1
   [junit4]   2> 658504 T1663 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 658511 T1663 oasc.ZkController.register We are http://127.0.0.1:33466/vh_ydi/p/collection1/ and leader is http://127.0.0.1:36564/vh_ydi/p/collection1/
   [junit4]   2> 658511 T1663 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33466/vh_ydi/p
   [junit4]   2> 658512 T1663 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 658512 T1663 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C1595 name=collection1 org.apache.solr.core.SolrCore@5c4594e1 url=http://127.0.0.1:33466/vh_ydi/p/collection1 node=127.0.0.1:33466_vh_ydi%2Fp C1595_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:33466/vh_ydi/p, state=down, node_name=127.0.0.1:33466_vh_ydi%2Fp, core=collection1}
   [junit4]   2> 658513 T1665 C1595 P33466 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 658513 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 658513 T1665 C1595 P33466 oasc.RecoveryStrat

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

decollectioncore"}
   [junit4]   1>   /solr/aliases.json (0)
   [junit4]   1>   /solr/live_nodes (5)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:33466_vh_ydi%2Fp (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:56444_vh_ydi%2Fp (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:43243_vh_ydi%2Fp (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:48632_vh_ydi%2Fp (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:36564_vh_ydi%2Fp (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:48632/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:48632_vh_ydi%2Fp",
   [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:36564/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:36564_vh_ydi%2Fp",
   [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:36564/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:36564_vh_ydi%2Fp",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:33466/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:33466_vh_ydi%2Fp",
   [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:56444/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:56444_vh_ydi%2Fp",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:43243/vh_ydi/p",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:43243_vh_ydi%2Fp",
   [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=87D988849DFD93E9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=SystemV/AST4ADT -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   28.4s J0 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:56444/vh_ydi/p/onenodecollectioncore returned non ok status:404, message:Can not find: /vh_ydi/p/onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([87D988849DFD93E9:63F069CEAA2F3D5]: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:780)
   [junit4]   2> 674491 T1588 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 28367 T1587 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> 675243 T1679 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 675243 T1679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 675244 T1679 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=404), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=404)), sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=de, timezone=SystemV/AST4ADT
   [junit4]   2> NOTE: Linux 3.2.0-52-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=3,free=73920160,total=177799168
   [junit4]   2> NOTE: All tests run in this JVM: [SampleTest, ZkControllerTest, SoftAutoCommitTest, OverseerCollectionProcessorTest, DOMUtilTest, CopyFieldTest, ReturnFieldsTest, ZkCLITest, SOLR749Test, QueryParsingTest, BadCopyFieldTest, ClusterStateUpdateTest, TestFieldResource, TestSolrQueryParserResource, PolyFieldTest, TestRandomDVFaceting, TestSolrIndexConfig, HdfsBasicDistributedZkTest, MoreLikeThisHandlerTest, TestLFUCache, DocValuesMissingTest, TestMaxScoreQueryParser, TestSearchPerf, WordBreakSolrSpellCheckerTest, SearchHandlerTest, TestSystemIdResolver, DocValuesTest, HdfsSyncSliceTest, TestSchemaVersionResource, ClusterStateTest, TestFunctionQuery, CacheHeaderTest, EchoParamsTest, TestCloudManagedSchema, HdfsRecoveryZkTest, SpatialFilterTest, TestElisionMultitermQuery, AnalysisAfterCoreReloadTest, SimpleFacetsTest, SliceStateTest, TestClassNameShortening, SystemInfoHandlerTest, TestFaceting, TestSuggestSpellingConverter, TestCopyFieldCollectionResource, TestJoin, StatelessScriptUpdateProcessorFactoryTest, AutoCommitTest, URLClassifyProcessorTest, LeaderElectionTest, QueryElevationComponentTest, BasicFunctionalityTest, PeerSyncTest, TestConfig, TestFieldTypeResource, CoreAdminHandlerTest, TestRealTimeGet, TestDocumentBuilder, FastVectorHighlighterTest, RecoveryZkTest, TestPerFieldSimilarity, TestValueSourceCache, TestLuceneMatchVersion, TestSolrXMLSerializer, BlockCacheTest, MBeansHandlerTest, UpdateRequestProcessorFactoryTest, TestLMJelinekMercerSimilarityFactory, SyncSliceTest, TestSurroundQueryParser, TestStressVersions, RegexBoostProcessorTest, TestJmxMonitoredMap, TestSort, SolrIndexSplitterTest, TestCoreContainer, TestSchemaNameResource, TestBadConfig, BasicDistributedZk2Test]
   [junit4] Completed on J0 in 29.15s, 1 test, 1 error <<< FAILURES!

[...truncated 510 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:396: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:389: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:455: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 324 suites, 1413 tests, 1 error, 34 ignored (6 assumptions)

Total time: 43 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -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



Mime
View raw message