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

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

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

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

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

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




Build Log:
[...truncated 9009 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 351307 T966 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 351311 T966 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1374982953672
   [junit4]   2> 351312 T966 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 351313 T967 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 351413 T966 oasc.ZkTestServer.run start zk server on port:50887
   [junit4]   2> 351415 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 351537 T973 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68216821 name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 351538 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 351539 T966 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 351550 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 351553 T975 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f663f66 name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 351554 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 351555 T966 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 351567 T966 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 351583 T966 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 351612 T966 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 351620 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 351621 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 351633 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 351634 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 351643 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 351644 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 351653 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 351654 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 351662 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 351663 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 351671 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 351672 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 351680 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 351681 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 351689 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 351690 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 351698 T966 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 351699 T966 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 351937 T966 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 351958 T966 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40006
   [junit4]   2> 351960 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 351961 T966 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 351962 T966 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072
   [junit4]   2> 351964 T966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/'
   [junit4]   2> 351982 T966 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/solr.xml
   [junit4]   2> 352040 T966 oasc.CoreContainer.<init> New CoreContainer 1348685923
   [junit4]   2> 352041 T966 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/]
   [junit4]   2> 352044 T966 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 352045 T966 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 352046 T966 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 352047 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 352048 T966 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 352049 T966 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 352050 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 352051 T966 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 352053 T966 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 352054 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 352066 T966 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50887/solr
   [junit4]   2> 352067 T966 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 352069 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 352073 T986 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55bc55bc name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 352074 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 352080 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 352091 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 352094 T988 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@338c338c name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 352095 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 352100 T966 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 352111 T966 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 352122 T966 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 352128 T966 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40006_
   [junit4]   2> 352155 T966 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40006_
   [junit4]   2> 352224 T966 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 352246 T966 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 352257 T966 oasc.Overseer.start Overseer (id=90110882852241411-127.0.0.1:40006_-n_0000000000) starting
   [junit4]   2> 352269 T966 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 352281 T990 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 352284 T966 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 352293 T966 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 352300 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 352311 T989 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 352316 T991 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 352316 T991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 352320 T991 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 353825 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 353829 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40006",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:40006_",
   [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> 353830 T989 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 353831 T989 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 353887 T988 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> 354321 T991 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 354321 T991 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/collection1
   [junit4]   2> 354322 T991 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 354324 T991 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 354325 T991 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 354328 T991 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/collection1/'
   [junit4]   2> 354330 T991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/collection1/lib/README' to classloader
   [junit4]   2> 354330 T991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/collection1/lib/classes/' to classloader
   [junit4]   2> 354365 T991 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 354403 T991 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 354407 T991 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 354422 T991 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 354838 T991 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 354839 T991 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 354840 T991 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 354845 T991 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 354848 T991 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 354886 T991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 354893 T991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 354902 T991 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 354906 T991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 354906 T991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 354907 T991 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 354911 T991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 354911 T991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 354912 T991 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 354922 T991 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374982954072/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/control/data/
   [junit4]   2> 354923 T991 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a5c3a5c
   [junit4]   2> 354924 T991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/control/data
   [junit4]   2> 354925 T991 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/control/data/index/
   [junit4]   2> 354925 T991 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 354926 T991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/control/data/index
   [junit4]   2> 354929 T991 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@21ea21ea lockFactory=org.apache.lucene.store.NativeFSLockFactory@57895789),segFN=segments_1,generation=1}
   [junit4]   2> 354929 T991 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 354935 T991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 354936 T991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 354937 T991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 354937 T991 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 354938 T991 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 354939 T991 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 354939 T991 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 354940 T991 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 354941 T991 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 354942 T991 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 354945 T991 oass.SolrIndexSearcher.<init> Opening Searcher@173d173d main
   [junit4]   2> 354946 T991 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 354947 T991 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 354954 T992 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@173d173d main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 354961 T991 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 354961 T991 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40006 collection:control_collection shard:shard1
   [junit4]   2> 354962 T991 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 354971 T991 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 354994 T991 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 355001 T991 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 355002 T991 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 355002 T991 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40006/collection1/
   [junit4]   2> 355003 T991 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 355004 T991 oasc.SyncStrategy.syncToMe http://127.0.0.1:40006/collection1/ has no replicas
   [junit4]   2> 355004 T991 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40006/collection1/ shard1
   [junit4]   2> 355005 T991 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 355402 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 355455 T988 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> 355477 T991 oasc.ZkController.register We are http://127.0.0.1:40006/collection1/ and leader is http://127.0.0.1:40006/collection1/
   [junit4]   2> 355478 T991 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40006
   [junit4]   2> 355479 T991 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 355479 T991 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 355480 T991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 355484 T991 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 355487 T966 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 355487 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 355489 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 355495 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 355497 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 355499 T995 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f300f3 name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 355500 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 355503 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 355510 T966 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 355690 T966 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 355692 T966 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57010
   [junit4]   2> 355693 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 355694 T966 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 355695 T966 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871
   [junit4]   2> 355696 T966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/'
   [junit4]   2> 355707 T966 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/solr.xml
   [junit4]   2> 355753 T966 oasc.CoreContainer.<init> New CoreContainer 211553436
   [junit4]   2> 355754 T966 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/]
   [junit4]   2> 355755 T966 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 355756 T966 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 355757 T966 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 355758 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 355758 T966 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 355759 T966 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 355760 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 355760 T966 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 355761 T966 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 355762 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 355770 T966 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50887/solr
   [junit4]   2> 355771 T966 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 355784 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 355788 T1006 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a9a3a9a name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 355789 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 355795 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 355802 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 355805 T1008 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@532b532b name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 355806 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 355822 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 356835 T966 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57010_
   [junit4]   2> 356839 T966 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57010_
   [junit4]   2> 356845 T988 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> 356849 T995 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 356851 T1008 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 356855 T988 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 356865 T1009 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 356866 T1009 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 356868 T1009 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 356975 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 356979 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40006",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:40006_",
   [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> 357028 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57010",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:57010_",
   [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> 357029 T989 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 357029 T989 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 357047 T995 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> 357047 T1008 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> 357047 T988 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> 357869 T1009 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 357870 T1009 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/collection1
   [junit4]   2> 357870 T1009 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 357873 T1009 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 357873 T1009 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 357877 T1009 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/collection1/'
   [junit4]   2> 357879 T1009 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/collection1/lib/README' to classloader
   [junit4]   2> 357879 T1009 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/collection1/lib/classes/' to classloader
   [junit4]   2> 357914 T1009 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 357966 T1009 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 357970 T1009 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 357978 T1009 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 358388 T1009 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 358389 T1009 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 358389 T1009 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 358395 T1009 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 358398 T1009 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 358435 T1009 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 358453 T1009 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 358461 T1009 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 358467 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 358468 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 358469 T1009 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 358475 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 358475 T1009 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 358476 T1009 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 358476 T1009 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374982957871/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty1/
   [junit4]   2> 358477 T1009 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a5c3a5c
   [junit4]   2> 358478 T1009 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty1
   [junit4]   2> 358479 T1009 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty1/index/
   [junit4]   2> 358480 T1009 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 358480 T1009 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty1/index
   [junit4]   2> 358482 T1009 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@370c370c lockFactory=org.apache.lucene.store.NativeFSLockFactory@221a221a),segFN=segments_1,generation=1}
   [junit4]   2> 358483 T1009 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 358491 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 358492 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 358493 T1009 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 358494 T1009 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 358495 T1009 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 358496 T1009 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 358497 T1009 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 358497 T1009 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 358498 T1009 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 358500 T1009 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 358503 T1009 oass.SolrIndexSearcher.<init> Opening Searcher@3f853f85 main
   [junit4]   2> 358504 T1009 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 358505 T1009 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 358512 T1010 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f853f85 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 358516 T1009 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 358517 T1009 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57010 collection:collection1 shard:shard1
   [junit4]   2> 358518 T1009 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 358527 T1009 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 358571 T1009 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 358579 T1009 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 358580 T1009 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 358580 T1009 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57010/collection1/
   [junit4]   2> 358581 T1009 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 358581 T1009 oasc.SyncStrategy.syncToMe http://127.0.0.1:57010/collection1/ has no replicas
   [junit4]   2> 358582 T1009 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57010/collection1/ shard1
   [junit4]   2> 358583 T1009 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 360080 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 360102 T995 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> 360102 T988 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> 360103 T1008 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> 360111 T1009 oasc.ZkController.register We are http://127.0.0.1:57010/collection1/ and leader is http://127.0.0.1:57010/collection1/
   [junit4]   2> 360150 T1009 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57010
   [junit4]   2> 360151 T1009 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 360152 T1009 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 360153 T1009 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 360158 T1009 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 360161 T966 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 360162 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 360163 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 360351 T966 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 360354 T966 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50490
   [junit4]   2> 360356 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 360357 T966 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 360359 T966 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529
   [junit4]   2> 360360 T966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/'
   [junit4]   2> 360377 T966 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/solr.xml
   [junit4]   2> 360429 T966 oasc.CoreContainer.<init> New CoreContainer 1630560560
   [junit4]   2> 360430 T966 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/]
   [junit4]   2> 360431 T966 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 360432 T966 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 360433 T966 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 360434 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 360434 T966 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 360435 T966 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 360436 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 360437 T966 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 360437 T966 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 360438 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 360446 T966 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50887/solr
   [junit4]   2> 360447 T966 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 360449 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 360452 T1022 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@467b467b name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 360453 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 360469 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 360476 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 360479 T1024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf51cf5 name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 360484 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 360497 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 361509 T966 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50490_
   [junit4]   2> 361511 T966 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50490_
   [junit4]   2> 361517 T995 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> 361518 T1008 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> 361518 T988 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> 361528 T1008 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 361528 T1024 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 361530 T995 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 361533 T988 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 361579 T1025 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 361579 T1025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 361582 T1025 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 361671 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 361675 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57010",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:57010_",
   [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> 361691 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50490",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:50490_",
   [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> 361691 T989 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 361692 T989 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 361707 T995 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> 361707 T988 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> 361707 T1024 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> 361708 T1008 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> 362583 T1025 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 362584 T1025 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/collection1
   [junit4]   2> 362584 T1025 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 362586 T1025 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 362587 T1025 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 362591 T1025 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/collection1/'
   [junit4]   2> 362592 T1025 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/collection1/lib/README' to classloader
   [junit4]   2> 362593 T1025 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/collection1/lib/classes/' to classloader
   [junit4]   2> 362628 T1025 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 362676 T1025 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 362680 T1025 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 362688 T1025 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 363160 T1025 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 363160 T1025 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 363161 T1025 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 363167 T1025 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 363170 T1025 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 363223 T1025 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 363230 T1025 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 363238 T1025 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 363241 T1025 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 363242 T1025 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 363243 T1025 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 363247 T1025 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 363247 T1025 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 363248 T1025 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 363248 T1025 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374982962529/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty2/
   [junit4]   2> 363249 T1025 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a5c3a5c
   [junit4]   2> 363251 T1025 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty2
   [junit4]   2> 363251 T1025 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty2/index/
   [junit4]   2> 363252 T1025 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 363252 T1025 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty2/index
   [junit4]   2> 363255 T1025 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@29122912 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5b3e5b3e),segFN=segments_1,generation=1}
   [junit4]   2> 363255 T1025 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 363271 T1025 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 363272 T1025 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 363273 T1025 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 363274 T1025 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 363275 T1025 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 363275 T1025 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 363276 T1025 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 363277 T1025 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 363278 T1025 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 363279 T1025 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 363282 T1025 oass.SolrIndexSearcher.<init> Opening Searcher@338e338e main
   [junit4]   2> 363283 T1025 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 363284 T1025 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 363293 T1026 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@338e338e main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 363299 T1025 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 363300 T1025 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50490 collection:collection1 shard:shard2
   [junit4]   2> 363301 T1025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 363312 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 363332 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 363351 T1025 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 363351 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 363352 T1025 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50490/collection1/
   [junit4]   2> 363352 T1025 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 363353 T1025 oasc.SyncStrategy.syncToMe http://127.0.0.1:50490/collection1/ has no replicas
   [junit4]   2> 363354 T1025 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50490/collection1/ shard2
   [junit4]   2> 363354 T1025 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 364747 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 364822 T995 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> 364822 T1008 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> 364823 T1024 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> 364824 T988 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> 364871 T1025 oasc.ZkController.register We are http://127.0.0.1:50490/collection1/ and leader is http://127.0.0.1:50490/collection1/
   [junit4]   2> 364872 T1025 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50490
   [junit4]   2> 364873 T1025 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 364873 T1025 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 364874 T1025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 364878 T1025 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 364881 T966 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 364882 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 364884 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 365154 T966 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 365156 T966 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42973
   [junit4]   2> 365157 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 365158 T966 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 365160 T966 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253
   [junit4]   2> 365161 T966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/'
   [junit4]   2> 365179 T966 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/solr.xml
   [junit4]   2> 365237 T966 oasc.CoreContainer.<init> New CoreContainer 1127367474
   [junit4]   2> 365238 T966 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/]
   [junit4]   2> 365239 T966 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 365240 T966 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 365241 T966 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 365241 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 365242 T966 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 365243 T966 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 365243 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 365244 T966 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 365245 T966 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 365246 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 365253 T966 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50887/solr
   [junit4]   2> 365254 T966 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 365256 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 365259 T1038 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ae03ae0 name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 365260 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 365265 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 365273 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 365277 T1040 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6db06db0 name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 365278 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 365298 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 366342 T966 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42973_
   [junit4]   2> 366347 T966 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42973_
   [junit4]   2> 366359 T995 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> 366361 T988 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> 366362 T1024 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> 366364 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 366365 T1008 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> 366369 T1040 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 366377 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50490",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:50490_",
   [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> 366378 T1024 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 366385 T995 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 366386 T1008 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 366394 T995 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> 366394 T1008 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> 366394 T1024 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> 366394 T1040 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> 366396 T1041 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 366397 T1041 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 366406 T1041 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 366417 T988 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 366417 T988 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> 367931 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 367935 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42973",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:42973_",
   [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> 367936 T989 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 367936 T989 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 367948 T1040 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> 367948 T995 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> 367948 T1024 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> 367949 T1008 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> 367949 T988 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> 368407 T1041 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 368408 T1041 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/collection1
   [junit4]   2> 368409 T1041 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 368413 T1041 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 368414 T1041 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 368421 T1041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/collection1/'
   [junit4]   2> 368423 T1041 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/collection1/lib/README' to classloader
   [junit4]   2> 368423 T1041 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/collection1/lib/classes/' to classloader
   [junit4]   2> 368461 T1041 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 368507 T1041 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 368512 T1041 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 368519 T1041 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 368971 T1041 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 368972 T1041 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 368972 T1041 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 368978 T1041 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 368981 T1041 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 369035 T1041 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 369042 T1041 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 369049 T1041 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 369053 T1041 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 369053 T1041 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 369054 T1041 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 369058 T1041 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 369058 T1041 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 369059 T1041 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 369060 T1041 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374982967253/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty3/
   [junit4]   2> 369060 T1041 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a5c3a5c
   [junit4]   2> 369062 T1041 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty3
   [junit4]   2> 369062 T1041 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty3/index/
   [junit4]   2> 369063 T1041 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 369063 T1041 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374982953672/jetty3/index
   [junit4]   2> 369066 T1041 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@65646564 lockFactory=org.apache.lucene.store.NativeFSLockFactory@79467946),segFN=segments_1,generation=1}
   [junit4]   2> 369066 T1041 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 369074 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 369075 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 369075 T1041 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 369076 T1041 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 369077 T1041 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 369078 T1041 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 369078 T1041 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 369079 T1041 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 369080 T1041 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 369082 T1041 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 369084 T1041 oass.SolrIndexSearcher.<init> Opening Searcher@15391539 main
   [junit4]   2> 369085 T1041 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 369086 T1041 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 369093 T1042 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15391539 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 369097 T1041 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 369097 T1041 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42973 collection:collection1 shard:shard1
   [junit4]   2> 369098 T1041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 369113 T1041 oasc.ZkController.register We are http://127.0.0.1:42973/collection1/ and leader is http://127.0.0.1:57010/collection1/
   [junit4]   2> 369114 T1041 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42973
   [junit4]   2> 369114 T1041 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 369115 T1041 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C1312 name=collection1 org.apache.solr.core.SolrCore@671b671b url=http://127.0.0.1:42973/collection1 node=127.0.0.1:42973_ C1312_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:42973, state=down, node_name=127.0.0.1:42973_, core=collection1}
   [junit4]   2> 369115 T1043 C1312 P42973 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 369116 T1043 C1312 P42973 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 369117 T1043 C1312 P42973 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 369117 T1041 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 369118 T1043 C1312 P42973 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 369121 T966 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 369122 T1043 C1312 P42973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 369122 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 369136 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 369142 T1001 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 369344 T966 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 369346 T966 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50275
   [junit4]   2> 369347 T966 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 369348 T966 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 369349 T966 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374982971505
   [junit4]   2> 369350 T966 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374982971505/'
   [junit4]   2> 369361 T966 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374982971505/solr.xml
   [junit4]   2> 369410 T966 oasc.CoreContainer.<init> New CoreContainer 1372213706
   [junit4]   2> 369411 T966 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374982971505/]
   [junit4]   2> 369414 T966 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 369415 T966 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 369416 T966 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 369417 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 369418 T966 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 369419 T966 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 369419 T966 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 369420 T966 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 369421 T966 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 369422 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 369429 T966 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50887/solr
   [junit4]   2> 369430 T966 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 369432 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 369434 T1055 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f2e3f2e name:ZooKeeperConnection Watcher:127.0.0.1:50887 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 369435 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 369440 T966 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 369447 T966 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 369450 T1057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e001e00 name:ZooKeeperConnection Watcher:127.0.0.1:50887/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 369451 T966 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 369463 T966 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 369477 T989 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 369482 T989 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42973",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:42973_",
   [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> 369496 T995 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> 369496 T1040 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> 369496 T988 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> 369496 T1008 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> 369508 T1024 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> 369510 T1057 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> 370144 T1001 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 370145 T1001 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={state=recovering&onlyIfLeader=true&checkLive=true&action=PREPRECOVERY&version=2&coreNodeName=core_node3&wt=javabin&nodeName=127.0.0.1:42973_&core=collection1} status=0 QTime=1003 
   [junit4]   2> 370478 T966 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50275_
   [junit4]   2> 370481 T966 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50275_
   [junit4]   2> 370489 T995 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> 370489 T1008 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred 

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

:
   [junit4]   1>          {
   [junit4]   1>            "base_url":"http://127.0.0.1:50490",
   [junit4]   1>            "node_name":"127.0.0.1:50490_",
   [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/90110882852241414-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:57010",
   [junit4]   1>            "node_name":"127.0.0.1:57010_",
   [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:40006_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:50490_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:42973_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:50275_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:57010_ (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:40006",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:40006_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "onenodecollection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:57010",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:57010_",
   [junit4]   1>                   "roles":"none",
   [junit4]   1>                   "core":"onenodecollectioncore",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "collection1":{
   [junit4]   1>           "shards":{
   [junit4]   1>             "shard1":{
   [junit4]   1>               "range":"80000000-ffffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:57010",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:57010_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:42973",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:42973_",
   [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:50490",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:50490_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:50275",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:50275_",
   [junit4]   1>                   "core":"collection1"}}}},
   [junit4]   1>           "router":"compositeId"}}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=8D75A37B277CB656 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_MA -Dtests.timezone=Asia/Tel_Aviv -Dtests.file.encoding=UTF-8
   [junit4] ERROR   34.0s J1 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:50490/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([8D75A37B277CB656:C932D635023D66A]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:738)
   [junit4]   2> 385300 T966 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 34012 T965 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> 385345 T1040 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 385346 T1040 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 386490 T1057 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 386491 T1057 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=218), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=218)), sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ar_MA, timezone=Asia/Tel_Aviv
   [junit4]   2> NOTE: Linux 3.2.0-49-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=2,free=3929192,total=53857280
   [junit4]   2> NOTE: All tests run in this JVM: [SuggesterTSTTest, FileUtilsTest, TestHashPartitioner, TestArbitraryIndexDir, HdfsUnloadDistributedZkTest, TestBM25SimilarityFactory, TestDistributedSearch, TestBinaryResponseWriter, TestRecoveryHdfs, TestMultiCoreConfBootstrap, IndexSchemaRuntimeFieldTest, TestCSVLoader, MultiTermTest, TestCloudManagedSchemaAddField, TermVectorComponentDistributedTest, TestStressLucene, SimplePostToolTest, DefaultValueUpdateProcessorTest, HighlighterConfigTest, TestCloudManagedSchema, TestQuerySenderNoQuery, UpdateParamsTest, FieldAnalysisRequestHandlerTest, BlockCacheTest, SuggesterWFSTTest, TestSuggestSpellingConverter, HardAutoCommitTest, SpellCheckCollatorTest, UniqFieldsUpdateProcessorFactoryTest, TestFastOutputStream, TestFoldingMultitermQuery, TestCopyFieldCollectionResource, DistanceFunctionTest, TestSolr4Spatial, TestStressReorder, XsltUpdateRequestHandlerTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 35.29s, 1 test, 1 error <<< FAILURES!

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

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



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

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6687/
Java: 32bit/ibm-j9-jdk6 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

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

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

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




Build Log:
[...truncated 9106 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
   [junit4]   2> 568208 T1948 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 568213 T1948 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1374998811321
   [junit4]   2> 568216 T1948 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 568217 T1949 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 568317 T1948 oasc.ZkTestServer.run start zk server on port:33834
   [junit4]   2> 568318 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 569362 T1952 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1041ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 569364 T1955 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16941694 name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 569365 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 569365 T1948 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 569374 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 569376 T1957 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ce82ce8 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 569377 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 569378 T1948 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 569385 T1948 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 569393 T1948 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 569399 T1948 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 569407 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 569408 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 569434 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 569435 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 569444 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 569446 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 569454 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 569455 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 569463 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 569464 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 569472 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 569473 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 569481 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 569482 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 569490 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 569491 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 569499 T1948 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 569500 T1948 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 569693 T1948 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 569715 T1948 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48822
   [junit4]   2> 569716 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 569717 T1948 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 569717 T1948 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625
   [junit4]   2> 569718 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/'
   [junit4]   2> 569730 T1948 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/solr.xml
   [junit4]   2> 569812 T1948 oasc.CoreContainer.<init> New CoreContainer 626468183
   [junit4]   2> 569813 T1948 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/]
   [junit4]   2> 569815 T1948 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 569816 T1948 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 569816 T1948 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 569817 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 569818 T1948 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 569819 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 569820 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 569821 T1948 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 569821 T1948 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 569823 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 569832 T1948 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33834/solr
   [junit4]   2> 569833 T1948 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 569834 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 569837 T1968 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@226f226f name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 569838 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 569842 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 569849 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 569852 T1970 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ee85ee8 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 569852 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 569856 T1948 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 569868 T1948 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 569879 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 569885 T1948 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48822_
   [junit4]   2> 569887 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48822_
   [junit4]   2> 569901 T1948 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 569916 T1948 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 569924 T1948 oasc.Overseer.start Overseer (id=90111922099060739-127.0.0.1:48822_-n_0000000000) starting
   [junit4]   2> 569934 T1948 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 569961 T1948 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 569969 T1948 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 569970 T1972 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 569977 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 569989 T1971 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 570018 T1973 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 570019 T1973 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 570022 T1973 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 571502 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 571506 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48822",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:48822_",
   [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> 571507 T1971 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
   [junit4]   2> 571507 T1971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 571519 T1970 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> 572023 T1973 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 572024 T1973 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/collection1
   [junit4]   2> 572024 T1973 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 572026 T1973 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 572027 T1973 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 572031 T1973 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/collection1/'
   [junit4]   2> 572032 T1973 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/collection1/lib/README' to classloader
   [junit4]   2> 572033 T1973 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/collection1/lib/classes/' to classloader
   [junit4]   2> 572087 T1973 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 572124 T1973 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 572130 T1973 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 572136 T1973 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 572590 T1973 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 572591 T1973 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 572592 T1973 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 572597 T1973 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 572600 T1973 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 572640 T1973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 572647 T1973 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 572655 T1973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 572661 T1973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 572662 T1973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 572662 T1973 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 572666 T1973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 572667 T1973 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 572668 T1973 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 572668 T1973 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1374998812625/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/control/data/
   [junit4]   2> 572669 T1973 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36433643
   [junit4]   2> 572670 T1973 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/control/data
   [junit4]   2> 572670 T1973 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/control/data/index/
   [junit4]   2> 572671 T1973 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 572672 T1973 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/control/data/index
   [junit4]   2> 572684 T1973 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@13e613e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@50875087),segFN=segments_1,generation=1}
   [junit4]   2> 572685 T1973 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 572691 T1973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 572692 T1973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 572692 T1973 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 572693 T1973 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 572694 T1973 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 572694 T1973 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 572695 T1973 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 572696 T1973 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 572697 T1973 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 572698 T1973 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 572700 T1973 oass.SolrIndexSearcher.<init> Opening Searcher@3e1a3e1a main
   [junit4]   2> 572702 T1973 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 572703 T1973 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 572708 T1974 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e1a3e1a main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 572711 T1973 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 572711 T1973 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48822 collection:control_collection shard:shard1
   [junit4]   2> 572712 T1973 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 572720 T1973 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 572742 T1973 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 572749 T1973 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 572750 T1973 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 572750 T1973 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48822/collection1/
   [junit4]   2> 572751 T1973 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 572751 T1973 oasc.SyncStrategy.syncToMe http://127.0.0.1:48822/collection1/ has no replicas
   [junit4]   2> 572752 T1973 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48822/collection1/ shard1
   [junit4]   2> 572752 T1973 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 573034 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 573075 T1970 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> 573123 T1973 oasc.ZkController.register We are http://127.0.0.1:48822/collection1/ and leader is http://127.0.0.1:48822/collection1/
   [junit4]   2> 573124 T1973 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48822
   [junit4]   2> 573124 T1973 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 573125 T1973 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 573125 T1973 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 573129 T1973 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 573132 T1948 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 573133 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 573134 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 573141 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 573143 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 573145 T1977 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28f128f1 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 573145 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 573149 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 573156 T1948 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 573351 T1948 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 573353 T1948 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35951
   [junit4]   2> 573354 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 573355 T1948 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 573365 T1948 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263
   [junit4]   2> 573366 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/'
   [junit4]   2> 573378 T1948 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/solr.xml
   [junit4]   2> 573415 T1948 oasc.CoreContainer.<init> New CoreContainer 35979813
   [junit4]   2> 573416 T1948 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/]
   [junit4]   2> 573418 T1948 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 573419 T1948 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 573419 T1948 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 573420 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 573421 T1948 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 573422 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 573422 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 573423 T1948 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 573424 T1948 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 573425 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 573433 T1948 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33834/solr
   [junit4]   2> 573434 T1948 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 573435 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 573438 T1988 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e864e86 name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 573438 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 573443 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 573450 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 573452 T1990 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67be67be name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 573452 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 573467 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 574495 T1948 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35951_
   [junit4]   2> 574497 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35951_
   [junit4]   2> 574504 T1970 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> 574506 T1977 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 574508 T1990 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 574513 T1970 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 574548 T1991 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 574549 T1991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 574552 T1991 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 574598 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 574603 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48822",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:48822_",
   [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> 574619 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:35951",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:35951_",
   [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> 574619 T1971 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
   [junit4]   2> 574620 T1971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 574632 T1990 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> 574632 T1970 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> 574634 T1977 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> 575552 T1991 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 575553 T1991 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/collection1
   [junit4]   2> 575554 T1991 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 575556 T1991 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 575557 T1991 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 575562 T1991 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/collection1/'
   [junit4]   2> 575564 T1991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/collection1/lib/README' to classloader
   [junit4]   2> 575564 T1991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/collection1/lib/classes/' to classloader
   [junit4]   2> 575605 T1991 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 575645 T1991 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 575650 T1991 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 575699 T1991 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 576124 T1991 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 576125 T1991 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 576126 T1991 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 576144 T1991 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 576148 T1991 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 576193 T1991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 576200 T1991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 576207 T1991 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 576211 T1991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 576212 T1991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 576212 T1991 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 576216 T1991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 576217 T1991 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 576218 T1991 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 576218 T1991 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1374998816263/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty1/
   [junit4]   2> 576219 T1991 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36433643
   [junit4]   2> 576220 T1991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty1
   [junit4]   2> 576221 T1991 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty1/index/
   [junit4]   2> 576221 T1991 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 576222 T1991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty1/index
   [junit4]   2> 576224 T1991 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b046b04 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3c173c17),segFN=segments_1,generation=1}
   [junit4]   2> 576225 T1991 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 576234 T1991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 576234 T1991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 576235 T1991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 576236 T1991 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 576237 T1991 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 576237 T1991 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 576238 T1991 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 576239 T1991 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 576240 T1991 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 576241 T1991 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 576244 T1991 oass.SolrIndexSearcher.<init> Opening Searcher@6bb06bb main
   [junit4]   2> 576245 T1991 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 576245 T1991 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 576277 T1992 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bb06bb main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 576283 T1991 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 576284 T1991 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35951 collection:collection1 shard:shard1
   [junit4]   2> 576284 T1991 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 576319 T1991 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 576345 T1991 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 576353 T1991 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 576354 T1991 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 576355 T1991 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35951/collection1/
   [junit4]   2> 576355 T1991 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 576356 T1991 oasc.SyncStrategy.syncToMe http://127.0.0.1:35951/collection1/ has no replicas
   [junit4]   2> 576356 T1991 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35951/collection1/ shard1
   [junit4]   2> 576357 T1991 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 577681 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 577706 T1977 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> 577706 T1990 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> 577708 T1970 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> 577733 T1991 oasc.ZkController.register We are http://127.0.0.1:35951/collection1/ and leader is http://127.0.0.1:35951/collection1/
   [junit4]   2> 577733 T1991 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35951
   [junit4]   2> 577734 T1991 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 577734 T1991 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 577735 T1991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 577740 T1991 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 577744 T1948 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 577745 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 577746 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 577925 T1948 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 577927 T1948 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58542
   [junit4]   2> 577928 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 577928 T1948 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 577929 T1948 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858
   [junit4]   2> 577930 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/'
   [junit4]   2> 577947 T1948 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/solr.xml
   [junit4]   2> 578007 T1948 oasc.CoreContainer.<init> New CoreContainer 1774283201
   [junit4]   2> 578008 T1948 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/]
   [junit4]   2> 578010 T1948 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 578010 T1948 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 578011 T1948 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 578012 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 578013 T1948 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 578013 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 578014 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 578015 T1948 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 578016 T1948 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 578017 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 578024 T1948 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33834/solr
   [junit4]   2> 578025 T1948 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 578026 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 578028 T2004 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53715371 name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 578029 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 578033 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 578041 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 578043 T2006 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34a034a0 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 578043 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 578056 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 579067 T1948 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58542_
   [junit4]   2> 579069 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58542_
   [junit4]   2> 579075 T1977 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> 579075 T1990 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> 579076 T1970 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> 579085 T2006 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 579089 T1970 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 579089 T1990 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 579091 T1977 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 579129 T2007 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 579129 T2007 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 579132 T2007 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 579235 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 579241 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:35951",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "node_name":"127.0.0.1:35951_",
   [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> 579255 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58542",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:58542_",
   [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> 579255 T1971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 579256 T1971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 579300 T1977 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> 579301 T2006 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> 579301 T1990 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> 579302 T1970 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> 580133 T2007 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 580134 T2007 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/collection1
   [junit4]   2> 580134 T2007 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 580136 T2007 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 580137 T2007 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 580141 T2007 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/collection1/'
   [junit4]   2> 580143 T2007 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/collection1/lib/README' to classloader
   [junit4]   2> 580143 T2007 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/collection1/lib/classes/' to classloader
   [junit4]   2> 580177 T2007 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 580214 T2007 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 580218 T2007 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 580224 T2007 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 580651 T2007 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 580652 T2007 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 580653 T2007 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 580658 T2007 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 580661 T2007 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 580697 T2007 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 580703 T2007 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 580711 T2007 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 580714 T2007 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 580715 T2007 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 580716 T2007 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 580720 T2007 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 580721 T2007 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 580721 T2007 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 580722 T2007 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1374998820858/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty2/
   [junit4]   2> 580722 T2007 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36433643
   [junit4]   2> 580724 T2007 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty2
   [junit4]   2> 580724 T2007 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty2/index/
   [junit4]   2> 580725 T2007 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 580726 T2007 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty2/index
   [junit4]   2> 580728 T2007 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6a486a48 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3bb83bb8),segFN=segments_1,generation=1}
   [junit4]   2> 580729 T2007 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 580737 T2007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 580738 T2007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 580739 T2007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 580741 T2007 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 580742 T2007 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 580743 T2007 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 580744 T2007 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 580745 T2007 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 580746 T2007 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 580749 T2007 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 580752 T2007 oass.SolrIndexSearcher.<init> Opening Searcher@1c951c95 main
   [junit4]   2> 580754 T2007 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 580766 T2007 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 580796 T2008 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c951c95 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 580800 T2007 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 580801 T2007 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58542 collection:collection1 shard:shard2
   [junit4]   2> 580802 T2007 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 580810 T2007 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 580833 T2007 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 580845 T2007 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 580846 T2007 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 580847 T2007 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58542/collection1/
   [junit4]   2> 580848 T2007 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 580849 T2007 oasc.SyncStrategy.syncToMe http://127.0.0.1:58542/collection1/ has no replicas
   [junit4]   2> 580849 T2007 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58542/collection1/ shard2
   [junit4]   2> 580850 T2007 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 582336 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 582373 T1977 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> 582373 T2006 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> 582374 T1990 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> 582375 T1970 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> 582422 T2007 oasc.ZkController.register We are http://127.0.0.1:58542/collection1/ and leader is http://127.0.0.1:58542/collection1/
   [junit4]   2> 582422 T2007 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58542
   [junit4]   2> 582466 T2007 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 582466 T2007 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 582467 T2007 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 582471 T2007 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 582474 T1948 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 582475 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 582476 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 582670 T1948 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 582673 T1948 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44374
   [junit4]   2> 582674 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 582675 T1948 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 582676 T1948 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588
   [junit4]   2> 582677 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/'
   [junit4]   2> 582689 T1948 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/solr.xml
   [junit4]   2> 582730 T1948 oasc.CoreContainer.<init> New CoreContainer 725494590
   [junit4]   2> 582731 T1948 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/]
   [junit4]   2> 582733 T1948 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 582734 T1948 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 582734 T1948 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 582735 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 582736 T1948 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 582736 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 582737 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 582738 T1948 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 582739 T1948 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 582740 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 582747 T1948 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33834/solr
   [junit4]   2> 582748 T1948 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 582749 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 582751 T2020 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@111e111e name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 582752 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 582756 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 582764 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 582766 T2022 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a442a44 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 582766 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 582789 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 583803 T1948 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44374_
   [junit4]   2> 583806 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44374_
   [junit4]   2> 583812 T1977 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> 583813 T1970 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> 583813 T1990 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> 583818 T2006 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> 583832 T2022 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 583834 T1990 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 583837 T1970 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 583841 T1977 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 583842 T2006 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 583880 T2023 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 583881 T2023 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 583885 T2023 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 583901 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 583905 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58542",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "node_name":"127.0.0.1:58542_",
   [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> 583917 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44374",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:44374_",
   [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> 583918 T1971 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 583919 T1971 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 583929 T1977 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> 583930 T1990 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> 583930 T2022 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> 583932 T1970 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> 583940 T2006 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> 584886 T2023 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 584887 T2023 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/collection1
   [junit4]   2> 584888 T2023 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 584890 T2023 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 584891 T2023 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 584895 T2023 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/collection1/'
   [junit4]   2> 584896 T2023 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/collection1/lib/README' to classloader
   [junit4]   2> 584897 T2023 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/collection1/lib/classes/' to classloader
   [junit4]   2> 584934 T2023 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 584969 T2023 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 584973 T2023 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 584980 T2023 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 585423 T2023 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 585424 T2023 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 585425 T2023 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 585432 T2023 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 585436 T2023 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 585495 T2023 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 585502 T2023 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 585509 T2023 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 585513 T2023 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 585513 T2023 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 585514 T2023 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 585518 T2023 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 585519 T2023 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 585519 T2023 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 585520 T2023 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1374998825588/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty3/
   [junit4]   2> 585520 T2023 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@36433643
   [junit4]   2> 585521 T2023 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty3
   [junit4]   2> 585522 T2023 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty3/index/
   [junit4]   2> 585522 T2023 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 585523 T2023 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1374998811321/jetty3/index
   [junit4]   2> 585525 T2023 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c4a1c4a lockFactory=org.apache.lucene.store.NativeFSLockFactory@14b914b9),segFN=segments_1,generation=1}
   [junit4]   2> 585526 T2023 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 585533 T2023 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 585534 T2023 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 585535 T2023 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 585536 T2023 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 585537 T2023 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 585537 T2023 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 585538 T2023 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 585539 T2023 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 585540 T2023 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 585541 T2023 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 585543 T2023 oass.SolrIndexSearcher.<init> Opening Searcher@49b149b1 main
   [junit4]   2> 585545 T2023 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 585545 T2023 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 585579 T2024 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49b149b1 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 585585 T2023 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 585586 T2023 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:44374 collection:collection1 shard:shard1
   [junit4]   2> 585587 T2023 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
   [junit4]   2> 585623 T2023 oasc.ZkController.register We are http://127.0.0.1:44374/collection1/ and leader is http://127.0.0.1:35951/collection1/
   [junit4]   2> 585623 T2023 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44374
   [junit4]   2> 585624 T2023 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 585624 T2023 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C2939 name=collection1 org.apache.solr.core.SolrCore@4c604c6 url=http://127.0.0.1:44374/collection1 node=127.0.0.1:44374_ C2939_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:44374, state=down, node_name=127.0.0.1:44374_, core=collection1}
   [junit4]   2> 585625 T2025 C2939 P44374 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 585626 T2025 C2939 P44374 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 585626 T2025 C2939 P44374 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 585627 T2023 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 585627 T2025 C2939 P44374 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 585630 T1948 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 585630 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 585631 T2025 C2939 P44374 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 585632 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 585639 T1986 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 585829 T1948 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 585831 T1948 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47449
   [junit4]   2> 585832 T1948 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 585833 T1948 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 585834 T1948 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374998828743
   [junit4]   2> 585835 T1948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374998828743/'
   [junit4]   2> 585847 T1948 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374998828743/solr.xml
   [junit4]   2> 585898 T1948 oasc.CoreContainer.<init> New CoreContainer 431954367
   [junit4]   2> 585898 T1948 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1374998828743/]
   [junit4]   2> 585900 T1948 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 585901 T1948 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 585901 T1948 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 585902 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 585903 T1948 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 585904 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 585905 T1948 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 585905 T1948 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 585906 T1948 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 585907 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 585914 T1948 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:33834/solr
   [junit4]   2> 585916 T1948 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 585917 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585920 T2037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23812381 name:ZooKeeperConnection Watcher:127.0.0.1:33834 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585920 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585925 T1948 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 585936 T1948 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 585938 T2039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15a315a3 name:ZooKeeperConnection Watcher:127.0.0.1:33834/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 585939 T1948 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 585957 T1948 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 586969 T1948 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47449_
   [junit4]   2> 586972 T1948 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47449_
   [junit4]   2> 586978 T1977 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> 586978 T2022 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> 586980 T1990 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> 586978 T1970 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> 586979 T2006 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> 586998 T1977 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 586999 T2039 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 587000 T2006 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 587001 T1990 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 587005 T1970 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 587006 T2022 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 587046 T1971 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 587051 T1971 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44374",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "node_name":"127.0.0.1:44374_",
   [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> 587063 T2006 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 587064 T1970 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 587065 T2039 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 587065 T1990 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 587064 T1977 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 587067 T2022 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:

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

rd1/election/90111922099060742-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:35951",
   [junit4]   1>            "node_name":"127.0.0.1:35951_",
   [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:48822_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:35951_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:44374_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:58542_ (0)
   [junit4]   1>    /solr/live_nodes/127.0.0.1:47449_ (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:48822",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:48822_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "onenodecollection":{
   [junit4]   1>           "shards":{"shard1":{
   [junit4]   1>               "range":"80000000-7fffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{"core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:35951",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:35951_",
   [junit4]   1>                   "roles":"none",
   [junit4]   1>                   "core":"onenodecollectioncore",
   [junit4]   1>                   "leader":"true"}}}},
   [junit4]   1>           "router":"compositeId"},
   [junit4]   1>         "collection1":{
   [junit4]   1>           "shards":{
   [junit4]   1>             "shard1":{
   [junit4]   1>               "range":"80000000-ffffffff",
   [junit4]   1>               "state":"active",
   [junit4]   1>               "replicas":{
   [junit4]   1>                 "core_node1":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:35951",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:35951_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node3":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:44374",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:44374_",
   [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:58542",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:58542_",
   [junit4]   1>                   "core":"collection1",
   [junit4]   1>                   "leader":"true"},
   [junit4]   1>                 "core_node4":{
   [junit4]   1>                   "base_url":"http://127.0.0.1:47449",
   [junit4]   1>                   "state":"active",
   [junit4]   1>                   "node_name":"127.0.0.1:47449_",
   [junit4]   1>                   "core":"collection1"}}}},
   [junit4]   1>           "router":"compositeId"}}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=1131006AFCA84704 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=is -Dtests.timezone=Asia/Katmandu -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   34.6s J1 | BasicDistributedZk2Test.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:58542/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([1131006AFCA84704:90D78E728BF72738]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:738)
   [junit4]   2> 602837 T1948 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 34654 T1947 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> 602911 T2022 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 602912 T2022 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 604026 T2039 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 604027 T2039 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> 604027 T2039 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=is, timezone=Asia/Katmandu
   [junit4]   2> NOTE: Linux 3.2.0-49-generic x86/IBM Corporation 1.6.0 (32-bit)/cpus=8,threads=3,free=4040856,total=56685568
   [junit4]   2> NOTE: All tests run in this JVM: [TestElisionMultitermQuery, SortByFunctionTest, SpellPossibilityIteratorTest, TestComponentsName, TestDefaultSimilarityFactory, TestIndexSearcher, FieldAnalysisRequestHandlerTest, ClusterStateTest, ConvertedLegacyTest, ZkSolrClientTest, TestRTGBase, IndexSchemaRuntimeFieldTest, TestCSVResponseWriter, RequestHandlersTest, OpenExchangeRatesOrgProviderTest, RequiredFieldsTest, IndexReaderFactoryTest, TestBinaryField, DistanceFunctionTest, TestZkChroot, TestSolrJ, TestWordDelimiterFilterFactory, TestNumberUtils, SuggesterTSTTest, XsltUpdateRequestHandlerTest, TestDefaultSearchFieldResource, TestRecovery, TestDynamicFieldCollectionResource, TestBinaryResponseWriter, StatsComponentTest, CurrencyFieldXmlFileTest, BadIndexSchemaTest, FileUtilsTest, SolrPluginUtilsTest, SolrTestCaseJ4Test, TestUpdate, TestSuggestSpellingConverter, TestStressLucene, TestSolrQueryParserResource, TestManagedSchemaFieldResource, HighlighterConfigTest, SpellCheckCollatorTest, EchoParamsTest, DebugComponentTest, SimplePostToolTest, IndexBasedSpellCheckerTest, StandardRequestHandlerTest, SolrCmdDistributorTest, InfoHandlerTest, HardAutoCommitTest, TermVectorComponentDistributedTest, CollectionsAPIDistributedZkTest, TestAddFieldRealTimeGet, TestMultiCoreConfBootstrap, SampleTest, DirectUpdateHandlerTest, HdfsSyncSliceTest, DirectSolrSpellCheckerTest, HdfsUnloadDistributedZkTest, TestHashPartitioner, TestCodecSupport, HdfsRecoveryZkTest, TestPropInject, TestRecoveryHdfs, TestLMJelinekMercerSimilarityFactory, DisMaxRequestHandlerTest, CopyFieldTest, TestDistributedGrouping, TimeZoneUtilsTest, TestPartialUpdateDeduplication, NoCacheHeaderTest, TestCollationField, UniqFieldsUpdateProcessorFactoryTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test]
   [junit4] Completed on J1 in 35.94s, 1 test, 1 error <<< FAILURES!

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

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