lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4311 - Still Failing
Date Thu, 12 Sep 2013 17:48:38 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4311/

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

Error Message:


Stack Trace:
java.lang.NullPointerException
	at __randomizedtesting.SeedInfo.seed([1A4C67F3207F8E85:9BAAE9EB5720EEB9]:0)
	at org.apache.solr.common.cloud.ZkCoreNodeProps.getBaseUrl(ZkCoreNodeProps.java:40)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.buildUrlMap(CloudSolrServer.java:404)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.directUpdate(CloudSolrServer.java:300)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:534)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.commit(AbstractFullDistribZkTestBase.java:1517)
	at org.apache.solr.cloud.BasicDistributedZk2Test.brindDownShardIndexSomeDocsAndRecover(BasicDistributedZk2Test.java:288)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:115)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)




Build Log:
[...truncated 9549 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 140806 T335 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 140813 T335 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1379006230972
   [junit4]   2> 140824 T335 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 140833 T336 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 141034 T335 oasc.ZkTestServer.run start zk server on port:36266
   [junit4]   2> 141299 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 141342 T337 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 143162 T341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dd15e9c name:ZooKeeperConnection Watcher:127.0.0.1:36266 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 143163 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 143171 T335 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 143323 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 143325 T344 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50774a82 name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 143326 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 143343 T335 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 143349 T335 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 143358 T335 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 143361 T335 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 143367 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 143368 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 143383 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 143384 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 143490 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 143491 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 143505 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 143505 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 143510 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 143511 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 143516 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 143516 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 143521 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 143522 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 143526 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 143527 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 143532 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 143533 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 143537 T335 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 143538 T335 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 143825 T335 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 143829 T335 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32601
   [junit4]   2> 143829 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 143830 T335 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 143830 T335 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702
   [junit4]   2> 143831 T335 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/'
   [junit4]   2> 143870 T335 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/solr.xml
   [junit4]   2> 143961 T335 oasc.CoreContainer.<init> New CoreContainer 522740299
   [junit4]   2> 143961 T335 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/]
   [junit4]   2> 143964 T335 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 143964 T335 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 143964 T335 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 143965 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 143965 T335 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 143966 T335 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 143966 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 143966 T335 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 143967 T335 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 143967 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 143989 T335 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 143989 T335 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 143990 T335 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36266/solr
   [junit4]   2> 144028 T335 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 144029 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 144031 T355 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@740879c0 name:ZooKeeperConnection Watcher:127.0.0.1:36266 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 144032 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 144042 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 144063 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 144065 T357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dc1367c name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 144065 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 144079 T335 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 144094 T335 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 144112 T335 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 144114 T335 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32601_
   [junit4]   2> 144121 T335 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32601_
   [junit4]   2> 144126 T335 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 144151 T335 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 144154 T335 oasc.Overseer.start Overseer (id=90374552379064323-127.0.0.1:32601_-n_0000000000) starting
   [junit4]   2> 144190 T335 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 144214 T359 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 144214 T335 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 144218 T335 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 144221 T335 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 144248 T358 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 144260 T360 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 144260 T360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 144263 T360 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 145760 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 145767 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32601_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:32601"}
   [junit4]   2> 145768 T358 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 145803 T358 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 145833 T357 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> 146266 T360 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 146266 T360 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/collection1
   [junit4]   2> 146267 T360 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 146268 T360 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 146268 T360 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 146270 T360 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/collection1/'
   [junit4]   2> 146272 T360 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/collection1/lib/README' to classloader
   [junit4]   2> 146273 T360 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/collection1/lib/classes/' to classloader
   [junit4]   2> 146404 T360 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 146477 T360 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 146580 T360 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 146595 T360 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 147234 T360 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 147250 T360 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 147253 T360 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 147271 T360 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 147276 T360 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 147281 T360 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 147282 T360 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 147283 T360 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 147283 T360 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 147284 T360 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 147285 T360 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 147285 T360 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 147285 T360 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1379006233702/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/control/data/
   [junit4]   2> 147285 T360 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2040c8a4
   [junit4]   2> 147286 T360 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/control/data
   [junit4]   2> 147286 T360 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/control/data/index/
   [junit4]   2> 147286 T360 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 147287 T360 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/control/data/index
   [junit4]   2> 147287 T360 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=34.060546875, floorSegmentMB=1.2275390625, forceMergeDeletesPctAllowed=29.462699104935304, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5705364105548586
   [junit4]   2> 147288 T360 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b48bc1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@376716d4),segFN=segments_1,generation=1}
   [junit4]   2> 147288 T360 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 147291 T360 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 147362 T360 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 147363 T360 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 147363 T360 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 147363 T360 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 147363 T360 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 147364 T360 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 147364 T360 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 147364 T360 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 147365 T360 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 147365 T360 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 147365 T360 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 147366 T360 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 147366 T360 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 147366 T360 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 147380 T360 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 147385 T360 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 147385 T360 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 147386 T360 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=52.9365234375, floorSegmentMB=1.0830078125, forceMergeDeletesPctAllowed=3.8367498476364337, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 147386 T360 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b48bc1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@376716d4),segFN=segments_1,generation=1}
   [junit4]   2> 147386 T360 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 147387 T360 oass.SolrIndexSearcher.<init> Opening Searcher@537e6788 main
   [junit4]   2> 147390 T361 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@537e6788 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 147391 T360 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 147391 T360 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32601 collection:control_collection shard:shard1
   [junit4]   2> 147403 T360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 147419 T360 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 147441 T360 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 147445 T360 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 147445 T360 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 147449 T360 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:32601/collection1/
   [junit4]   2> 147450 T360 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 147450 T360 oasc.SyncStrategy.syncToMe http://127.0.0.1:32601/collection1/ has no replicas
   [junit4]   2> 147450 T360 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:32601/collection1/ shard1
   [junit4]   2> 147450 T360 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 148844 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 148867 T357 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> 148896 T360 oasc.ZkController.register We are http://127.0.0.1:32601/collection1/ and leader is http://127.0.0.1:32601/collection1/
   [junit4]   2> 148896 T360 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32601
   [junit4]   2> 148896 T360 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 148897 T360 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 148897 T360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 148899 T360 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 148901 T335 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 148901 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 148902 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 148939 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 148948 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 148952 T364 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d9d87f3 name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 148952 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 148954 T335 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 148959 T335 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 149156 T335 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 149158 T335 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50613
   [junit4]   2> 149158 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 149159 T335 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 149159 T335 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117
   [junit4]   2> 149159 T335 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/'
   [junit4]   2> 149186 T335 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/solr.xml
   [junit4]   2> 149253 T335 oasc.CoreContainer.<init> New CoreContainer 992347793
   [junit4]   2> 149254 T335 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/]
   [junit4]   2> 149255 T335 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 149255 T335 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 149256 T335 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 149256 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 149256 T335 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 149257 T335 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 149257 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 149257 T335 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 149258 T335 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 149258 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 149270 T335 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 149271 T335 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 149271 T335 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36266/solr
   [junit4]   2> 149272 T335 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 149272 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 149277 T375 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dfd6212 name:ZooKeeperConnection Watcher:127.0.0.1:36266 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 149277 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 149280 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 149290 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 149292 T377 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c61d18f name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 149292 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 149304 T335 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 150309 T335 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50613_
   [junit4]   2> 150311 T335 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50613_
   [junit4]   2> 150314 T357 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> 150316 T377 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 150316 T364 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 150318 T357 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 150341 T378 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 150341 T378 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 150343 T378 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 150378 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 150379 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:32601_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:32601"}
   [junit4]   2> 150385 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50613_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50613"}
   [junit4]   2> 150386 T358 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 150386 T358 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 150397 T357 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> 150398 T364 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> 150397 T377 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> 151344 T378 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 151344 T378 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/collection1
   [junit4]   2> 151344 T378 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 151357 T378 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 151357 T378 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 151359 T378 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/collection1/'
   [junit4]   2> 151361 T378 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/collection1/lib/README' to classloader
   [junit4]   2> 151361 T378 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/collection1/lib/classes/' to classloader
   [junit4]   2> 151412 T378 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 151460 T378 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 151563 T378 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 151576 T378 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 152266 T378 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 152281 T378 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 152285 T378 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 152310 T378 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 152316 T378 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 152321 T378 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 152323 T378 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 152324 T378 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 152324 T378 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 152326 T378 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 152326 T378 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 152326 T378 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 152327 T378 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1379006239117/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty1/
   [junit4]   2> 152327 T378 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2040c8a4
   [junit4]   2> 152328 T378 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty1
   [junit4]   2> 152328 T378 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty1/index/
   [junit4]   2> 152329 T378 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 152329 T378 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty1/index
   [junit4]   2> 152330 T378 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=34.060546875, floorSegmentMB=1.2275390625, forceMergeDeletesPctAllowed=29.462699104935304, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5705364105548586
   [junit4]   2> 152330 T378 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@46fa7042 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@22852e09),segFN=segments_1,generation=1}
   [junit4]   2> 152331 T378 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 152336 T378 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 152336 T378 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 152337 T378 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 152337 T378 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 152337 T378 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 152338 T378 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 152338 T378 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 152339 T378 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 152339 T378 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 152340 T378 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 152341 T378 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 152341 T378 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 152341 T378 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 152342 T378 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 152343 T378 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 152361 T378 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 152367 T378 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 152367 T378 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 152368 T378 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=52.9365234375, floorSegmentMB=1.0830078125, forceMergeDeletesPctAllowed=3.8367498476364337, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 152369 T378 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@46fa7042 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@22852e09),segFN=segments_1,generation=1}
   [junit4]   2> 152369 T378 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 152369 T378 oass.SolrIndexSearcher.<init> Opening Searcher@220b807c main
   [junit4]   2> 152374 T379 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@220b807c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 152377 T378 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 152377 T378 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50613 collection:collection1 shard:shard1
   [junit4]   2> 152378 T378 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 152389 T378 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 152414 T378 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 152418 T378 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 152418 T378 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 152418 T378 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50613/collection1/
   [junit4]   2> 152418 T378 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 152419 T378 oasc.SyncStrategy.syncToMe http://127.0.0.1:50613/collection1/ has no replicas
   [junit4]   2> 152419 T378 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50613/collection1/ shard1
   [junit4]   2> 152419 T378 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 153417 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 153438 T377 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> 153438 T357 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> 153438 T364 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> 153456 T378 oasc.ZkController.register We are http://127.0.0.1:50613/collection1/ and leader is http://127.0.0.1:50613/collection1/
   [junit4]   2> 153456 T378 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50613
   [junit4]   2> 153456 T378 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 153456 T378 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 153456 T378 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 153458 T378 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 153459 T335 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 153460 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 153460 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 153732 T335 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 153735 T335 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:31203
   [junit4]   2> 153736 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 153736 T335 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 153737 T335 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626
   [junit4]   2> 153737 T335 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/'
   [junit4]   2> 153780 T335 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/solr.xml
   [junit4]   2> 153879 T335 oasc.CoreContainer.<init> New CoreContainer 89581008
   [junit4]   2> 153880 T335 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/]
   [junit4]   2> 153882 T335 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 153883 T335 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 153883 T335 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 153883 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 153884 T335 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 153884 T335 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 153885 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 153885 T335 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 153886 T335 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 153886 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 153907 T335 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 153907 T335 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 153908 T335 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36266/solr
   [junit4]   2> 153908 T335 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 153910 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 153913 T391 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34c9631e name:ZooKeeperConnection Watcher:127.0.0.1:36266 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 153914 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 153929 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 153942 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 153945 T393 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23e9989b name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 153945 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 153966 T335 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 154954 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 154956 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50613_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50613"}
   [junit4]   2> 154972 T377 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> 154972 T357 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> 154972 T393 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> 154972 T364 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> 154973 T335 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:31203_
   [junit4]   2> 154977 T335 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:31203_
   [junit4]   2> 154987 T357 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> 154988 T364 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 154988 T393 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 154988 T364 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> 154988 T377 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 154989 T393 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> 154989 T377 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> 154990 T357 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 155000 T394 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 155000 T394 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 155002 T394 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 156482 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 156484 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:31203_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:31203"}
   [junit4]   2> 156484 T358 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 156484 T358 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 156524 T357 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> 156524 T364 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> 156524 T377 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> 156524 T393 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> 157005 T394 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 157005 T394 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/collection1
   [junit4]   2> 157005 T394 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 157007 T394 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 157007 T394 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 157008 T394 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/collection1/'
   [junit4]   2> 157010 T394 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/collection1/lib/classes/' to classloader
   [junit4]   2> 157011 T394 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/collection1/lib/README' to classloader
   [junit4]   2> 157058 T394 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 157103 T394 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 157205 T394 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 157214 T394 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 157892 T394 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 157910 T394 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 157914 T394 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 157937 T394 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 157944 T394 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 157950 T394 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 157951 T394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 157952 T394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 157952 T394 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 157954 T394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 157954 T394 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 157954 T394 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 157955 T394 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1379006243626/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty2/
   [junit4]   2> 157955 T394 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2040c8a4
   [junit4]   2> 157956 T394 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty2
   [junit4]   2> 157956 T394 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty2/index/
   [junit4]   2> 157957 T394 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 157957 T394 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty2/index
   [junit4]   2> 157958 T394 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=34.060546875, floorSegmentMB=1.2275390625, forceMergeDeletesPctAllowed=29.462699104935304, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5705364105548586
   [junit4]   2> 157959 T394 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e9c483a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ae49b6),segFN=segments_1,generation=1}
   [junit4]   2> 157959 T394 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 157964 T394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 157965 T394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 157965 T394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 157966 T394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 157966 T394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 157966 T394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 157967 T394 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 157967 T394 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 157967 T394 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 157968 T394 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 157969 T394 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 157969 T394 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 157970 T394 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 157971 T394 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 157971 T394 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 157998 T394 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 158005 T394 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 158006 T394 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 158007 T394 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=52.9365234375, floorSegmentMB=1.0830078125, forceMergeDeletesPctAllowed=3.8367498476364337, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 158008 T394 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e9c483a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ae49b6),segFN=segments_1,generation=1}
   [junit4]   2> 158008 T394 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 158008 T394 oass.SolrIndexSearcher.<init> Opening Searcher@52813e1e main
   [junit4]   2> 158014 T395 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52813e1e main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 158017 T394 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 158017 T394 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:31203 collection:collection1 shard:shard2
   [junit4]   2> 158018 T394 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 158030 T394 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 158053 T394 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 158057 T394 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 158058 T394 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 158058 T394 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:31203/collection1/
   [junit4]   2> 158058 T394 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 158058 T394 oasc.SyncStrategy.syncToMe http://127.0.0.1:31203/collection1/ has no replicas
   [junit4]   2> 158058 T394 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:31203/collection1/ shard2
   [junit4]   2> 158059 T394 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 159534 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 159555 T357 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> 159555 T377 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> 159555 T364 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> 159555 T393 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> 159561 T394 oasc.ZkController.register We are http://127.0.0.1:31203/collection1/ and leader is http://127.0.0.1:31203/collection1/
   [junit4]   2> 159561 T394 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:31203
   [junit4]   2> 159561 T394 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 159561 T394 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 159562 T394 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 159564 T394 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 159566 T335 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
   [junit4]   2> 159566 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 159567 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 159895 T335 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 159898 T335 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:31219
   [junit4]   2> 159899 T335 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 159899 T335 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 159900 T335 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739
   [junit4]   2> 159900 T335 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/'
   [junit4]   2> 159945 T335 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/solr.xml
   [junit4]   2> 160053 T335 oasc.CoreContainer.<init> New CoreContainer 1480050164
   [junit4]   2> 160054 T335 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/]
   [junit4]   2> 160056 T335 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 160056 T335 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 160057 T335 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 160057 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 160058 T335 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 160058 T335 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 160059 T335 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 160059 T335 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 160060 T335 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 160060 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 160077 T335 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 160077 T335 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 160078 T335 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:36266/solr
   [junit4]   2> 160078 T335 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 160079 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 160082 T407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45b2729 name:ZooKeeperConnection Watcher:127.0.0.1:36266 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 160083 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 160086 T335 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 160097 T335 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 160100 T409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c6b32cf name:ZooKeeperConnection Watcher:127.0.0.1:36266/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 160100 T335 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 160113 T335 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 161065 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 161067 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:31203_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:31203"}
   [junit4]   2> 161082 T357 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> 161082 T377 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> 161082 T393 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> 161082 T364 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> 161082 T409 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> 161120 T335 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:31219_
   [junit4]   2> 161147 T335 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:31219_
   [junit4]   2> 161175 T409 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> 161175 T357 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> 161175 T377 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 161176 T377 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> 161176 T393 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 161176 T364 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 161176 T393 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> 161176 T364 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> 161188 T357 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 161188 T409 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 161203 T410 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 161203 T410 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 161228 T410 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 162591 T358 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 162592 T358 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:31219_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:31219"}
   [junit4]   2> 162593 T358 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 162593 T358 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 162614 T357 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> 162614 T409 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> 162614 T393 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> 162614 T364 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> 162614 T377 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> 163231 T410 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 163231 T410 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/collection1
   [junit4]   2> 163231 T410 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 163233 T410 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 163233 T410 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 163234 T410 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/collection1/'
   [junit4]   2> 163236 T410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/collection1/lib/classes/' to classloader
   [junit4]   2> 163237 T410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/collection1/lib/README' to classloader
   [junit4]   2> 163304 T410 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 163370 T410 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 163473 T410 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 163487 T410 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 163985 T410 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 163995 T410 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 163998 T410 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 164019 T410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 164023 T410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 164028 T410 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 164029 T410 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 164030 T410 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 164030 T410 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 164031 T410 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 164032 T410 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 164032 T410 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 164032 T410 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1379006249739/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/
   [junit4]   2> 164032 T410 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2040c8a4
   [junit4]   2> 164033 T410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3
   [junit4]   2> 164034 T410 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index/
   [junit4]   2> 164034 T410 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 164034 T410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index
   [junit4]   2> 164034 T410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=34.060546875, floorSegmentMB=1.2275390625, forceMergeDeletesPctAllowed=29.462699104935304, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5705364105548586
   [junit4]   2> 164035 T410 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e5cf0f0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6513cc69),segFN=segments_1,generation=1}
   [junit4]   2> 164035 T410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 164039 T410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 164039 T410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 164040 T410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 164040 T410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 164040 T410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 164040 T410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 164041 T410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 164042 T410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 164042 T410 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 164042 T410 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 164043 T410 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 164043 T410 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 164044 T410 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 164044 T410 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 164044 T410 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 164056 T410 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 164060 T410 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 164060 T410 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 164061 T410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=52.9365234375, floorSegmentMB=1.0830078125, forceMergeDeletesPctAllowed=3.8367498476364337, segmentsPerTier=42.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 164061 T410 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e5cf0f0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6513cc69),segFN=segments_1,generation=1}
   [junit4]   2> 164061 T410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 164062 T410 oass.SolrIndexSearcher.<init> Opening Searcher@3d3900cd main
   [junit4]   2> 164066 T411 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d3900cd main{StandardDirectoryReader(segments_1

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

istributedZk2Test-1379006230971/jetty3
   [junit4]   2> 211341 T409 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index;done=false>>]
   [junit4]   2> 211342 T409 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1379006230971/jetty3/index
   [junit4]   2> 211342 T409 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 211343 T409 oasc.SolrException.log ERROR There was a problem trying to register as the leader:org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1041)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:184)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:181)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:181)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:392)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:361)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:348)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:95)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:255)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 	
   [junit4]   2> 211343 T409 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/90374552379064330-core_node3-n_0000000001
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:152)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:149)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:149)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:258)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 211344 T409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 211344 T409 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 211345 T409 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 211345 T409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 211345 T409 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 211345 T409 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene45: {foo_b=PostingsFormat(name=FSTPulsing41), n_f1=PostingsFormat(name=Lucene41WithOrds), foo_d=PostingsFormat(name=SimpleText), foo_f=PostingsFormat(name=FSTPulsing41), n_tl1=PostingsFormat(name=Lucene41WithOrds), n_d1=PostingsFormat(name=TestBloomFilteredLucene41Postings), rnd_b=PostingsFormat(name=SimpleText), intDefault=PostingsFormat(name=Lucene41WithOrds), n_td1=PostingsFormat(name=Lucene41WithOrds), timestamp=PostingsFormat(name=TestBloomFilteredLucene41Postings), id=PostingsFormat(name=SimpleText), range_facet_sl=PostingsFormat(name=SimpleText), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), oddField_s=PostingsFormat(name=SimpleText), multiDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tf1=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_dt1=PostingsFormat(name=Lucene41WithOrds), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_ti1=PostingsFormat(name=SimpleText), text=PostingsFormat(name=FSTPulsing41), _version_=PostingsFormat(name=Lucene41WithOrds), SubjectTerms_mfacet=PostingsFormat(name=Lucene41WithOrds), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_tdt1=PostingsFormat(name=Lucene41WithOrds), other_tl1=PostingsFormat(name=Lucene41WithOrds), n_l1=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=PostingsFormat(name=Lucene41WithOrds)}, docValues:{timestamp=DocValuesFormat(name=Asserting)}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_CO, timezone=SystemV/PST8
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=16,threads=2,free=51503720,total=268435456
   [junit4]   2> NOTE: All tests run in this JVM: [NotRequiredUniqueKeyTest, SolrTestCaseJ4Test, JSONWriterTest, TestSolrXml, TestFieldTypeResource, OpenCloseCoreStressTest, TestCSVLoader, SuggesterTSTTest, TestSchemaVersionResource, StatsComponentTest, HdfsBasicDistributedZk2Test, SolrPluginUtilsTest, ConvertedLegacyTest, HighlighterTest, AddSchemaFieldsUpdateProcessorFactoryTest, RequiredFieldsTest, InfoHandlerTest, TestBinaryResponseWriter, TestShardHandlerFactory, SolrCoreCheckLockOnStartupTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 71.31s, 1 test, 1 error <<< FAILURES!

[...truncated 899 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:396: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:376: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:455: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1230: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:873: There were test failures: 325 suites, 1446 tests, 1 error, 34 ignored (6 assumptions)

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



Mime
View raw message