You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/08/21 03:32:12 UTC

[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build # 7098 - Failure!

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

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

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

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:45742/_k/onenodecollectioncore returned non ok status:404, message:Can not find: /_k/onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([47731CEB6A70C7DB:C69592F31D2FA7E7]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)




Build Log:
[...truncated 9540 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 92264 T496 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_k/
   [junit4]   2> 92270 T496 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1377047563431
   [junit4]   2> 92272 T496 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 92273 T497 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 92373 T496 oasc.ZkTestServer.run start zk server on port:43446
   [junit4]   2> 92376 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92419 T503 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@653e3976 name:ZooKeeperConnection Watcher:127.0.0.1:43446 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92420 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92420 T496 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 92432 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92434 T505 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e6606a5 name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92434 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92436 T496 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 92443 T496 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 92447 T496 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 92451 T496 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 92456 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 92456 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 92463 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 92464 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 92469 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 92469 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 92473 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 92474 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 92478 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 92479 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 92483 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 92484 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 92490 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 92491 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 92495 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 92496 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 92500 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 92501 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 92506 T496 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 92507 T496 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 92626 T496 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 92633 T496 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38643
   [junit4]   2> 92634 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 92635 T496 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 92636 T496 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674
   [junit4]   2> 92636 T496 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/'
   [junit4]   2> 92645 T496 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/solr.xml
   [junit4]   2> 92679 T496 oasc.CoreContainer.<init> New CoreContainer 2091004965
   [junit4]   2> 92680 T496 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/]
   [junit4]   2> 92681 T496 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 92682 T496 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 92682 T496 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 92683 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 92683 T496 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 92684 T496 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 92685 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 92685 T496 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 92686 T496 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 92686 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 92695 T496 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43446/solr
   [junit4]   2> 92701 T496 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 92703 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92705 T516 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e6ba90d name:ZooKeeperConnection Watcher:127.0.0.1:43446 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92705 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92708 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 92719 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92720 T518 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8affb347 name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92720 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92724 T496 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 92730 T496 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 92736 T496 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 92739 T496 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38643__k
   [junit4]   2> 92742 T496 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38643__k
   [junit4]   2> 92747 T496 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 92756 T496 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 92760 T496 oasc.Overseer.start Overseer (id=90246189117472771-127.0.0.1:38643__k-n_0000000000) starting
   [junit4]   2> 92770 T496 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 92779 T520 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 92780 T496 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 92785 T496 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 92788 T496 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 92795 T519 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 92801 T521 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 92801 T521 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 92802 T521 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 94302 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 94304 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:38643/_k",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:38643__k",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 94304 T519 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 94308 T519 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 94314 T518 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> 94803 T521 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 94804 T521 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/collection1
   [junit4]   2> 94805 T521 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 94806 T521 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 94807 T521 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 94809 T521 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/collection1/'
   [junit4]   2> 94810 T521 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/collection1/lib/classes/' to classloader
   [junit4]   2> 94811 T521 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/collection1/lib/README' to classloader
   [junit4]   2> 94866 T521 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 94920 T521 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 94922 T521 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 94933 T521 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 95328 T521 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 95335 T521 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 95338 T521 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 95364 T521 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 95374 T521 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 95381 T521 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 95383 T521 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 95383 T521 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 95383 T521 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 95386 T521 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 95386 T521 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 95387 T521 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 95387 T521 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1377047563674/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/control/data/
   [junit4]   2> 95388 T521 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c6f0e16
   [junit4]   2> 95390 T521 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/control/data
   [junit4]   2> 95390 T521 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/control/data/index/
   [junit4]   2> 95391 T521 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 95393 T521 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/control/data/index
   [junit4]   2> 95396 T521 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=85.998046875, floorSegmentMB=1.5595703125, forceMergeDeletesPctAllowed=10.465038802073535, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 95400 T521 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ea8dcb13 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@aaaa529e),segFN=segments_1,generation=1}
   [junit4]   2> 95400 T521 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 95404 T521 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 95404 T521 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 95405 T521 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 95405 T521 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 95406 T521 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 95407 T521 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 95407 T521 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 95408 T521 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 95408 T521 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 95409 T521 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 95410 T521 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 95410 T521 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 95411 T521 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 95412 T521 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 95412 T521 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 95414 T521 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 95418 T521 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 95419 T521 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 95420 T521 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 95421 T521 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@ea8dcb13 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@aaaa529e),segFN=segments_1,generation=1}
   [junit4]   2> 95421 T521 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 95422 T521 oass.SolrIndexSearcher.<init> Opening Searcher@f0f3ce30 main
   [junit4]   2> 95426 T522 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f0f3ce30 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 95427 T521 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 95428 T521 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38643/_k collection:control_collection shard:shard1
   [junit4]   2> 95431 T521 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 95446 T521 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 95464 T521 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 95468 T521 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 95469 T521 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 95470 T521 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38643/_k/collection1/
   [junit4]   2> 95471 T521 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 95471 T521 oasc.SyncStrategy.syncToMe http://127.0.0.1:38643/_k/collection1/ has no replicas
   [junit4]   2> 95472 T521 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38643/_k/collection1/ shard1
   [junit4]   2> 95472 T521 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 95819 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 95831 T518 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> 95882 T521 oasc.ZkController.register We are http://127.0.0.1:38643/_k/collection1/ and leader is http://127.0.0.1:38643/_k/collection1/
   [junit4]   2> 95883 T521 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38643/_k
   [junit4]   2> 95883 T521 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 95884 T521 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 95884 T521 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 95887 T521 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 95888 T496 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 95889 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 95899 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 95913 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 95918 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 95928 T525 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@41173457 name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 95929 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 95931 T496 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 95937 T496 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 96139 T496 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 96147 T496 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43805
   [junit4]   2> 96148 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 96149 T496 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 96150 T496 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098
   [junit4]   2> 96151 T496 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/'
   [junit4]   2> 96164 T496 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/solr.xml
   [junit4]   2> 96205 T496 oasc.CoreContainer.<init> New CoreContainer -1726572668
   [junit4]   2> 96205 T496 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/]
   [junit4]   2> 96207 T496 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 96207 T496 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 96208 T496 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 96208 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 96209 T496 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 96209 T496 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 96210 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 96211 T496 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 96211 T496 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 96212 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 96219 T496 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43446/solr
   [junit4]   2> 96220 T496 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 96222 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 96224 T536 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@701414d9 name:ZooKeeperConnection Watcher:127.0.0.1:43446 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 96224 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 96226 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 96238 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 96240 T538 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3402fe93 name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 96240 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 96245 T496 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 97250 T496 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43805__k
   [junit4]   2> 97252 T496 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43805__k
   [junit4]   2> 97331 T518 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 97331 T538 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 97332 T525 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 97332 T518 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> 97340 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 97342 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:38643/_k",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:38643__k",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 97344 T539 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 97345 T539 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 97346 T539 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 97350 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:43805__k",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 97351 T519 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 97351 T519 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 97358 T538 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> 97358 T525 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> 97360 T518 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> 98348 T539 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 98348 T539 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/collection1
   [junit4]   2> 98348 T539 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 98349 T539 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 98350 T539 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 98352 T539 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/collection1/'
   [junit4]   2> 98352 T539 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/collection1/lib/classes/' to classloader
   [junit4]   2> 98353 T539 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/collection1/lib/README' to classloader
   [junit4]   2> 98384 T539 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 98418 T539 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 98422 T539 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 98433 T539 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 98906 T539 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 98912 T539 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 98915 T539 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 98935 T539 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 98942 T539 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 98949 T539 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 98951 T539 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 98951 T539 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 98952 T539 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 98953 T539 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 98954 T539 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 98955 T539 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 98955 T539 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1377047567098/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty1/
   [junit4]   2> 98956 T539 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c6f0e16
   [junit4]   2> 98957 T539 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty1
   [junit4]   2> 98958 T539 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty1/index/
   [junit4]   2> 98958 T539 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 98959 T539 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty1/index
   [junit4]   2> 98960 T539 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=85.998046875, floorSegmentMB=1.5595703125, forceMergeDeletesPctAllowed=10.465038802073535, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 98961 T539 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c217359 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ca1e419),segFN=segments_1,generation=1}
   [junit4]   2> 98962 T539 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 98966 T539 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 98967 T539 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 98967 T539 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 98968 T539 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 98968 T539 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 98969 T539 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 98970 T539 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 98970 T539 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 98971 T539 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 98972 T539 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 98973 T539 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 98973 T539 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 98974 T539 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 98975 T539 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 98976 T539 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 98978 T539 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 98982 T539 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 98982 T539 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 98983 T539 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 98985 T539 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c217359 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4ca1e419),segFN=segments_1,generation=1}
   [junit4]   2> 98985 T539 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 98986 T539 oass.SolrIndexSearcher.<init> Opening Searcher@42033d69 main
   [junit4]   2> 98989 T540 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42033d69 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 98993 T539 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 98994 T539 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43805/_k collection:collection1 shard:shard1
   [junit4]   2> 98994 T539 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 99002 T539 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 99010 T539 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 99013 T539 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 99014 T539 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 99014 T539 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43805/_k/collection1/
   [junit4]   2> 99015 T539 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 99015 T539 oasc.SyncStrategy.syncToMe http://127.0.0.1:43805/_k/collection1/ has no replicas
   [junit4]   2> 99016 T539 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43805/_k/collection1/ shard1
   [junit4]   2> 99016 T539 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 100371 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 100380 T525 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> 100380 T538 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> 100381 T518 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> 100392 T539 oasc.ZkController.register We are http://127.0.0.1:43805/_k/collection1/ and leader is http://127.0.0.1:43805/_k/collection1/
   [junit4]   2> 100392 T539 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43805/_k
   [junit4]   2> 100392 T539 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 100393 T539 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 100393 T539 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 100395 T539 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 100396 T496 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 100397 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 100397 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 100493 T496 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 100498 T496 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45742
   [junit4]   2> 100499 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 100500 T496 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 100500 T496 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567
   [junit4]   2> 100501 T496 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/'
   [junit4]   2> 100509 T496 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/solr.xml
   [junit4]   2> 100561 T496 oasc.CoreContainer.<init> New CoreContainer 1620896251
   [junit4]   2> 100562 T496 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/]
   [junit4]   2> 100564 T496 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 100567 T496 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 100568 T496 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 100569 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 100570 T496 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 100571 T496 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 100572 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 100573 T496 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 100574 T496 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 100575 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 100589 T496 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43446/solr
   [junit4]   2> 100590 T496 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 100593 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 100595 T552 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a6ae6c10 name:ZooKeeperConnection Watcher:127.0.0.1:43446 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 100595 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 100598 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 100609 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 100610 T554 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d040adc6 name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 100610 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 100615 T496 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 101620 T496 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45742__k
   [junit4]   2> 101621 T496 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45742__k
   [junit4]   2> 101625 T518 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 101625 T538 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 101626 T525 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 101625 T518 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> 101626 T554 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 101626 T538 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> 101626 T525 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> 101635 T555 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 101636 T555 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 101637 T555 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 101889 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 101890 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:43805__k",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 101920 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45742/_k",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:45742__k",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 101921 T519 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 101921 T519 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 101926 T554 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> 101926 T538 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> 101927 T525 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> 101927 T518 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> 102637 T555 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 102638 T555 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/collection1
   [junit4]   2> 102638 T555 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 102639 T555 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 102639 T555 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 102640 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/collection1/'
   [junit4]   2> 102641 T555 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/collection1/lib/classes/' to classloader
   [junit4]   2> 102642 T555 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/collection1/lib/README' to classloader
   [junit4]   2> 102673 T555 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 102706 T555 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 102707 T555 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 102714 T555 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 103073 T555 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 103080 T555 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 103082 T555 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 103099 T555 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 103104 T555 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 103109 T555 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 103111 T555 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 103111 T555 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 103112 T555 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 103113 T555 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 103113 T555 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 103114 T555 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 103114 T555 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1377047571567/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty2/
   [junit4]   2> 103114 T555 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c6f0e16
   [junit4]   2> 103115 T555 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty2
   [junit4]   2> 103116 T555 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty2/index/
   [junit4]   2> 103116 T555 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 103117 T555 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty2/index
   [junit4]   2> 103117 T555 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=85.998046875, floorSegmentMB=1.5595703125, forceMergeDeletesPctAllowed=10.465038802073535, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 103118 T555 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b22ab13c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bf88ad59),segFN=segments_1,generation=1}
   [junit4]   2> 103118 T555 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 103121 T555 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 103122 T555 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 103122 T555 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 103123 T555 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 103123 T555 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 103123 T555 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 103124 T555 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 103124 T555 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 103125 T555 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 103125 T555 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 103126 T555 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 103126 T555 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 103127 T555 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 103127 T555 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 103128 T555 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 103129 T555 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 103132 T555 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 103133 T555 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 103133 T555 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 103134 T555 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b22ab13c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bf88ad59),segFN=segments_1,generation=1}
   [junit4]   2> 103134 T555 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 103135 T555 oass.SolrIndexSearcher.<init> Opening Searcher@5c0f999a main
   [junit4]   2> 103138 T556 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c0f999a main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 103140 T555 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 103140 T555 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45742/_k collection:collection1 shard:shard2
   [junit4]   2> 103140 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 103149 T555 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 103156 T555 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 103159 T555 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 103159 T555 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 103160 T555 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45742/_k/collection1/
   [junit4]   2> 103160 T555 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 103161 T555 oasc.SyncStrategy.syncToMe http://127.0.0.1:45742/_k/collection1/ has no replicas
   [junit4]   2> 103161 T555 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45742/_k/collection1/ shard2
   [junit4]   2> 103161 T555 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 103434 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 103449 T554 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> 103449 T525 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> 103449 T518 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> 103449 T538 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> 103468 T555 oasc.ZkController.register We are http://127.0.0.1:45742/_k/collection1/ and leader is http://127.0.0.1:45742/_k/collection1/
   [junit4]   2> 103468 T555 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45742/_k
   [junit4]   2> 103469 T555 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 103469 T555 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 103469 T555 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 103472 T555 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 103474 T496 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 103474 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 103475 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 103564 T496 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 103570 T496 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41770
   [junit4]   2> 103572 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 103572 T496 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 103573 T496 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645
   [junit4]   2> 103574 T496 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/'
   [junit4]   2> 103582 T496 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/solr.xml
   [junit4]   2> 103615 T496 oasc.CoreContainer.<init> New CoreContainer 2069538026
   [junit4]   2> 103615 T496 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/]
   [junit4]   2> 103617 T496 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 103617 T496 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 103618 T496 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 103618 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 103619 T496 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 103620 T496 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 103620 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 103621 T496 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 103621 T496 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 103622 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 103630 T496 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43446/solr
   [junit4]   2> 103631 T496 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 103633 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 103635 T568 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@503343de name:ZooKeeperConnection Watcher:127.0.0.1:43446 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 103635 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 103637 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 103647 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 103649 T570 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3788a1bc name:ZooKeeperConnection Watcher:127.0.0.1:43446/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 103649 T496 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 103653 T496 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 104658 T496 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41770__k
   [junit4]   2> 104659 T496 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41770__k
   [junit4]   2> 104662 T554 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> 104663 T525 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 104663 T538 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 104663 T518 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 104664 T538 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> 104663 T570 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 104664 T525 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> 104665 T554 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 104664 T518 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> 104672 T571 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 104673 T571 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 104674 T571 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 104958 T519 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 104959 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45742/_k",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:45742__k",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 104963 T519 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:41770/_k",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:41770__k",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 104964 T519 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 104964 T519 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 104979 T570 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> 104979 T525 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> 104979 T554 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> 104979 T518 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> 104979 T538 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> 105674 T571 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 105675 T571 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/collection1
   [junit4]   2> 105675 T571 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 105676 T571 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 105676 T571 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 105677 T571 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/collection1/'
   [junit4]   2> 105678 T571 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/collection1/lib/classes/' to classloader
   [junit4]   2> 105679 T571 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/collection1/lib/README' to classloader
   [junit4]   2> 105726 T571 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 105779 T571 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 105780 T571 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 105787 T571 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 106150 T571 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 106158 T571 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 106160 T571 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 106178 T571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 106183 T571 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 106187 T571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 106189 T571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 106189 T571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 106190 T571 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 106191 T571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 106191 T571 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 106192 T571 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 106192 T571 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1377047574645/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty3/
   [junit4]   2> 106193 T571 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c6f0e16
   [junit4]   2> 106194 T571 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty3
   [junit4]   2> 106194 T571 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty3/index/
   [junit4]   2> 106194 T571 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 106195 T571 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1377047563431/jetty3/index
   [junit4]   2> 106195 T571 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=85.998046875, floorSegmentMB=1.5595703125, forceMergeDeletesPctAllowed=10.465038802073535, segmentsPerTier=49.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 106196 T571 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@daf9f3d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ce8697ac),segFN=segments_1,generation=1}
   [junit4]   2> 106197 T571 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 106200 T571 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 106201 T571 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 106201 T571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 106202 T571 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 106202 T571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 106202 T571 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 106203 T571 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 106203 T571 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 106204 T571 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 106204 T571 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 106205 T571 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 106205 T571 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 106206 T571 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 106206 T571 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 106207 T571 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 106208 T571 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 106211 T571 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 106211 T571 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 106212 T571 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=12, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 106212 T571 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@daf9f3d2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ce8697ac),segFN=segments_1,generation=1}
   [junit4]   2> 106213 T571 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 106213 T571 oass.SolrIndexSearcher.<init> Opening Searcher@bd7a6ae1 main
   [junit4]   2> 106217 T572 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bd7a6ae1 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 106219 T571 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 106219 T571 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41770/_k collection:collection1 shard:shard1
   [junit4]   2> 106220 T571 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 106233 T571 oasc.ZkController.register We are http://127.0.0.1:41770/_k/collection1/ and leader is http://127.0.0.1:43805/_k/collection1/
   [junit4]   2> 106234 T571 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41770/_k
   [junit4]   2> 106234 T571 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 106235 T571 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C258 name=collection1 org.apache.solr.core.SolrCore@7883a9fb url=http://127.0.0.1:41770/_k/collection1 node=127.0.0.1:41770__k C258_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:41770/_k, state=down, node_name=127.0.0.1:41770__k, core=collection1}
   [junit4]   2> 106237 T573 C258 P41770 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 106237 T571 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 106238 T573 C258 P41770 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 106239 T573 C258 P41770 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 106239 T573 C258 P41770 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 106244 T496 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 106244 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 106244 T573 C258 P41770 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 106245 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 106344 T533 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 106369 T496 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 106375 T496 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36763
   [junit4]   2> 106376 T496 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 106377 T496 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 106378 T496 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1377047577418
   [junit4]   2> 106378 T496 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1377047577418/'
   [junit4]   2> 106386 T496 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1377047577418/solr.xml
   [junit4]   2> 106418 T496 oasc.CoreContainer.<init> New CoreContainer -1592592108
   [junit4]   2> 106419 T496 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1377047577418/]
   [junit4]   2> 106420 T496 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 106421 T496 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 106422 T496 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 106422 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 106423 T496 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 106423 T496 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 106424 T496 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 106424 T496 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 106425 T496 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 106426 T496 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 106431 T496 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43446/solr
   [junit4]   2> 106432 T496 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 106434 T496 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [

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

rs (2)
   [junit4]   1>      /solr/collections/collection1/leaders/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   1>            "node_name":"127.0.0.1:43805__k",
   [junit4]   1>            "core":"collection1"}
   [junit4]   1>      /solr/collections/collection1/leaders/shard2 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:45742/_k",
   [junit4]   1>            "node_name":"127.0.0.1:45742__k",
   [junit4]   1>            "core":"collection1"}
   [junit4]   1>     /solr/collections/collection1/shards (0)
   [junit4]   1>    /solr/collections/onenodecollection (2)
   [junit4]   1>    DATA:
   [junit4]   1>        {
   [junit4]   1>          "router":"compositeId",
   [junit4]   1>          "configName":"conf1"}
   [junit4]   1>     /solr/collections/onenodecollection/leader_elect (1)
   [junit4]   1>      /solr/collections/onenodecollection/leader_elect/shard1 (1)
   [junit4]   1>       /solr/collections/onenodecollection/leader_elect/shard1/election (1)
   [junit4]   1>        /solr/collections/onenodecollection/leader_elect/shard1/election/90246189117472774-core_node1-n_0000000000 (0)
   [junit4]   1>     /solr/collections/onenodecollection/leaders (1)
   [junit4]   1>      /solr/collections/onenodecollection/leaders/shard1 (0)
   [junit4]   1>      DATA:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   1>            "node_name":"127.0.0.1:43805__k",
   [junit4]   1>            "core":"onenodecollectioncore"}
   [junit4]   1>   /solr/aliases.json (0)
   [junit4]   1>   /solr/live_nodes (5)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:38643__k (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:43805__k (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:45742__k (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:41770__k (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:36763__k (0)
   [junit4]   1>   /solr/clusterstate.json (0)
   [junit4]   1>   DATA:
   [junit4]   1>       {
   [junit4]   1>         "control_collection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:38643/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:38643__k",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"},
   [junit4]   1>         "onenodecollection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:43805__k",
   [junit4]   1>                   "roles":"none",
   [junit4]   1>                   "core":"onenodecollectioncore",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"},
   [junit4]   1>         "collection1":{
   [junit4]   1>           "shards":{
   [junit4]   1>             "shard1":{
   [junit4]   1>               "range":"80000000-ffffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:43805/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:43805__k",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:41770/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:41770__k",
   [junit4]   1>                   "core":"collection1"}}},
   [junit4]   1>             "shard2":{
   [junit4]   1>               "range":"0-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node2":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:45742/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:45742__k",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:36763/_k",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:36763__k",
   [junit4]   1>                   "core":"collection1"}}}},
   [junit4]   1>           "maxShardsPerNode":"1",
   [junit4]   1>           "router":"compositeId",
   [junit4]   1>           "replicationFactor":"1"}}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=47731CEB6A70C7DB -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_IN -Dtests.timezone=Europe/San_Marino -Dtests.file.encoding=UTF-8
   [junit4] ERROR   29.9s J1 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:45742/_k/onenodecollectioncore returned non ok status:404, message:Can not find: /_k/onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([47731CEB6A70C7DB:C69592F31D2FA7E7]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:780)
   [junit4]   2> 122127 T496 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 29872 T495 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> 123054 T587 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 123054 T587 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> 123055 T587 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=en_IN, timezone=Europe/San_Marino
   [junit4]   2> NOTE: Linux 3.2.0-52-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=2,free=19242184,total=157089792
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolr4Spatial, TestStressReorder, TimeZoneUtilsTest, StatsComponentTest, TestArbitraryIndexDir, HardAutoCommitTest, AddBlockUpdateTest, NotRequiredUniqueKeyTest, TestRecoveryHdfs, NumericFieldsTest, TestBinaryResponseWriter, DateFieldTest, ZkSolrClientTest, TestWordDelimiterFilterFactory, TestSolrQueryParserDefaultOperatorResource, TestSolrXmlPersistence, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 30.91s, 1 test, 1 error <<< FAILURES!

[...truncated 877 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:389: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:382: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:450: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 323 suites, 1402 tests, 1 error, 35 ignored (6 assumptions)

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