lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_25) - Build # 6996 - Failure!
Date Mon, 19 Aug 2013 17:15:35 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6996/
Java: 32bit/jdk1.7.0_25 -server -XX:+UseParallelGC

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

Error Message:
collection already exists: awholynewcollection_0

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_0
	at __randomizedtesting.SeedInfo.seed([180F372952506007:99E9B931250F003B]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:424)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:318)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1571)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1585)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:481)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:152)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)




Build Log:
[...truncated 9908 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 620502 T1172 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /nzy/mn
   [junit4]   2> 620506 T1172 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1376931110020
   [junit4]   2> 620506 T1172 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 620507 T1173 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 620607 T1172 oasc.ZkTestServer.run start zk server on port:59900
   [junit4]   2> 620607 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 623008 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 2400ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 623012 T1179 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1856466 name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 623012 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 623012 T1172 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 624930 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1916ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 625418 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 625472 T1181 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5386 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 625473 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 625473 T1172 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 625561 T1172 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 625606 T1172 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 625683 T1172 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 625742 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 625742 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 626139 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 626139 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 626245 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 626246 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 626932 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 626933 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 627279 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627279 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 627375 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627376 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 627398 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627398 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 627524 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627524 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 627631 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627632 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 627739 T1172 oasc.AbstractZkTestCase.putConfig put /var/lib/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> 627740 T1172 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 627875 T1172 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 627879 T1172 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46646
   [junit4]   2> 627879 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 627879 T1172 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 627880 T1172 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323
   [junit4]   2> 627880 T1172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/'
   [junit4]   2> 627889 T1172 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/solr.xml
   [junit4]   2> 627917 T1172 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 627917 T1172 oasc.CoreContainer.<init> New CoreContainer 31888544
   [junit4]   2> 627917 T1172 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/]
   [junit4]   2> 627919 T1172 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 627919 T1172 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 627919 T1172 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 627919 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 627920 T1172 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 627920 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 627920 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 627921 T1172 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 627921 T1172 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 627921 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 627925 T1172 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59900/solr
   [junit4]   2> 627925 T1172 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 627925 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 627964 T1192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@197aec0 name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 627964 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 628020 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 628023 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 628088 T1194 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@175f150 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 628088 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 628158 T1172 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 628284 T1172 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 628332 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 628397 T1172 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46646_nzy%2Fmn
   [junit4]   2> 628462 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46646_nzy%2Fmn
   [junit4]   2> 628507 T1172 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 628697 T1172 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 628757 T1172 oasc.Overseer.start Overseer (id=90238557226401795-127.0.0.1:46646_nzy%2Fmn-n_0000000000) starting
   [junit4]   2> 628876 T1172 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 628964 T1196 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 628965 T1172 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 629044 T1172 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 629109 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 629111 T1195 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 629112 T1172 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323
   [junit4]   2> 629134 T1172 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/conf/
   [junit4]   2> 629135 T1172 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 629135 T1172 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 629135 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 629136 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 629138 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 629139 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 629173 T1199 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84aeac name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 629173 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 629175 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 629178 T1172 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 629249 T1172 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 629250 T1172 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56172
   [junit4]   2> 629251 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 629251 T1172 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 629252 T1172 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692
   [junit4]   2> 629252 T1172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/'
   [junit4]   2> 629261 T1172 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/solr.xml
   [junit4]   2> 629290 T1172 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 629290 T1172 oasc.CoreContainer.<init> New CoreContainer 26360902
   [junit4]   2> 629290 T1172 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/]
   [junit4]   2> 629291 T1172 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 629292 T1172 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 629292 T1172 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 629292 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 629292 T1172 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 629293 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 629293 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 629293 T1172 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 629293 T1172 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 629294 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 629296 T1172 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59900/solr
   [junit4]   2> 629297 T1172 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 629297 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 629328 T1210 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@baae12 name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 629328 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 629361 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 629366 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 629406 T1212 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d2c1c7 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 629406 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 629475 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 630484 T1172 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56172_nzy%2Fmn
   [junit4]   2> 631857 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1371ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 631858 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56172_nzy%2Fmn
   [junit4]   2> 632137 T1194 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 632137 T1212 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 632137 T1199 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 632220 T1172 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692
   [junit4]   2> 632262 T1172 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/conf/
   [junit4]   2> 632262 T1172 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 632263 T1172 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 632263 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 632263 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 632330 T1172 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 632332 T1172 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51097
   [junit4]   2> 632332 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 632333 T1172 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 632333 T1172 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780
   [junit4]   2> 632333 T1172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780/'
   [junit4]   2> 632342 T1172 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780/solr.xml
   [junit4]   2> 632370 T1172 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 632371 T1172 oasc.CoreContainer.<init> New CoreContainer 22298456
   [junit4]   2> 632371 T1172 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780/]
   [junit4]   2> 632372 T1172 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 632372 T1172 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 632372 T1172 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 632372 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 632373 T1172 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 632373 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 632373 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 632373 T1172 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 632374 T1172 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 632374 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 632376 T1172 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59900/solr
   [junit4]   2> 632377 T1172 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 632378 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 632605 T1224 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@116b77e name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 632605 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 632676 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 632681 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 632717 T1226 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e13c76 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 632718 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 632786 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 633790 T1172 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51097_nzy%2Fmn
   [junit4]   2> 638807 T1174 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x140977d5c860004, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 
   [junit4]   2> 638907 T1199 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84aeac name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
   [junit4]   2> 638907 T1199 oascc.ConnectionManager.process zkClient has disconnected
   [junit4]   2> 639402 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 5610ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 639402 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51097_nzy%2Fmn
   [junit4]   2> 639403 T1176 oazs.NIOServerCnxn.sendBuffer ERROR Unexpected Exception:  java.nio.channels.CancelledKeyException
   [junit4]   2> 	at sun.nio.ch.SelectionKeyImpl.ensureValid(SelectionKeyImpl.java:73)
   [junit4]   2> 	at sun.nio.ch.SelectionKeyImpl.interestOps(SelectionKeyImpl.java:77)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.sendBuffer(NIOServerCnxn.java:153)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.sendResponse(NIOServerCnxn.java:1076)
   [junit4]   2> 	at org.apache.zookeeper.server.FinalRequestProcessor.processRequest(FinalRequestProcessor.java:170)
   [junit4]   2> 	at org.apache.zookeeper.server.SyncRequestProcessor.run(SyncRequestProcessor.java:138)
   [junit4]   2> 
   [junit4]   2> 640057 T1199 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@84aeac name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 643655 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 4251ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 643657 T1212 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 643657 T1194 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 643657 T1199 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 643657 T1226 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 644096 T1172 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780
   [junit4]   2> 644125 T1172 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1376931121780/conf/
   [junit4]   2> 644126 T1172 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 644126 T1172 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 644127 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 644127 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 644191 T1172 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 644192 T1172 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39140
   [junit4]   2> 644193 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 644194 T1172 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 644194 T1172 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643
   [junit4]   2> 644194 T1172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/'
   [junit4]   2> 644203 T1172 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/solr.xml
   [junit4]   2> 644230 T1172 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 644230 T1172 oasc.CoreContainer.<init> New CoreContainer 17514398
   [junit4]   2> 644231 T1172 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/]
   [junit4]   2> 644231 T1172 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 644232 T1172 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 644232 T1172 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 644232 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 644232 T1172 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 644233 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 644233 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 644233 T1172 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 644233 T1172 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 644234 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 644236 T1172 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59900/solr
   [junit4]   2> 644236 T1172 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 644237 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 644334 T1238 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@108c189 name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 644335 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 644397 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 644399 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 644452 T1240 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bf8414 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 644453 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 644619 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 645623 T1172 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39140_nzy%2Fmn
   [junit4]   2> 645706 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39140_nzy%2Fmn
   [junit4]   2> 645763 T1212 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 645763 T1194 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 645763 T1226 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 645764 T1240 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 645763 T1199 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 645832 T1172 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643
   [junit4]   2> 645858 T1172 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/conf/
   [junit4]   2> 645858 T1172 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 645859 T1172 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 645859 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 645859 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 645923 T1172 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 645925 T1172 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:42733
   [junit4]   2> 645925 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 645926 T1172 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 645926 T1172 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376
   [junit4]   2> 645926 T1172 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/'
   [junit4]   2> 645936 T1172 oasc.ConfigSolr.fromFile Loading container configuration from /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/solr.xml
   [junit4]   2> 645963 T1172 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 645964 T1172 oasc.CoreContainer.<init> New CoreContainer 26373175
   [junit4]   2> 645964 T1172 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/]
   [junit4]   2> 645965 T1172 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 645965 T1172 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 645965 T1172 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 645965 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 645966 T1172 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 645966 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 645966 T1172 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 645966 T1172 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 645967 T1172 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 645967 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 645969 T1172 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59900/solr
   [junit4]   2> 645970 T1172 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 645970 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646008 T1252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c68d46 name:ZooKeeperConnection Watcher:127.0.0.1:59900 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646008 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 646041 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 646045 T1172 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 646086 T1254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d73193 name:ZooKeeperConnection Watcher:127.0.0.1:59900/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 646086 T1172 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 648265 T1176 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 2177ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 648718 T1172 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 649724 T1172 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42733_nzy%2Fmn
   [junit4]   2> 649819 T1172 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42733_nzy%2Fmn
   [junit4]   2> 649853 T1212 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649853 T1194 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649853 T1226 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649853 T1254 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649853 T1240 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649853 T1199 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 649891 T1172 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376
   [junit4]   2> 649924 T1172 oasc.CorePropertiesLocator.discoverUnder Found core conf in /var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/conf/
   [junit4]   2> 649924 T1172 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 649925 T1172 oass.SolrDispatchFilter.init user.dir=/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 649925 T1172 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 649925 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 649928 T1172 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 649932 T1208 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
   [junit4]   2> 649963 T1194 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 650008 T1196 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "name":"nodes_used_collection",
   [junit4]   2> 	  "replicationFactor":"2"}
   [junit4]   2> 650009 T1196 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "name":"nodes_used_collection",
   [junit4]   2> 	  "replicationFactor":"2"}
   [junit4]   2> 651322 T1195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 651323 T1195 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: nodes_used_collection
   [junit4]   2> 651323 T1195 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with shards [shard1, shard2]
   [junit4]   2> 651596 T1212 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> 651596 T1226 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> 651596 T1194 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> 651596 T1240 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> 651596 T1254 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> 651596 T1199 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> 651685 T1196 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 651685 T1196 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:42733_nzy%2Fmn
   [junit4]   2> 651685 T1196 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:56172_nzy%2Fmn
   [junit4]   2> 651686 T1196 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:46646_nzy%2Fmn
   [junit4]   2> 651687 T1196 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:39140_nzy%2Fmn
   [junit4]   2> 651689 T1250 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
   [junit4]   2> 651689 T1207 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
   [junit4]   2> 651689 T1235 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
   [junit4]   2> 651689 T1189 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
   [junit4]   2> 651717 T1250 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 651828 T1207 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 651828 T1189 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 651828 T1235 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 653177 T1195 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 653177 T1195 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"nodes_used_collection_shard1_replica1",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42733_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42733/nzy/mn"}
   [junit4]   2> 653307 T1195 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"nodes_used_collection_shard1_replica2",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56172_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:56172/nzy/mn"}
   [junit4]   2> 653441 T1195 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"nodes_used_collection_shard2_replica2",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39140_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39140/nzy/mn"}
   [junit4]   2> 653562 T1195 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node4",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"nodes_used_collection_shard2_replica1",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:46646_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:46646/nzy/mn"}
   [junit4]   2> 653849 T1212 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> 653849 T1194 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> 653849 T1226 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> 653849 T1199 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> 653849 T1254 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> 653849 T1240 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> 654718 T1250 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica1
   [junit4]   2> 654719 T1250 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1
   [junit4]   2> 654719 T1250 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 654721 T1250 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
   [junit4]   2> 654721 T1250 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 654723 T1250 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 654723 T1250 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
   [junit4]   2> 654829 T1207 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard1_replica2
   [junit4]   2> 654829 T1189 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica1
   [junit4]   2> 654829 T1235 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for nodes_used_collection_shard2_replica2
   [junit4]   2> 654830 T1189 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1
   [junit4]   2> 654829 T1207 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2
   [junit4]   2> 654830 T1235 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2
   [junit4]   2> 654830 T1189 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 654830 T1235 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 654830 T1207 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
   [junit4]   2> 654841 T1189 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 654841 T1250 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 654841 T1207 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 654842 T1207 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 654841 T1235 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 654843 T1250 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/'
   [junit4]   2> 654841 T1189 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 654843 T1207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/'
   [junit4]   2> 654843 T1235 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
   [junit4]   2> 654845 T1189 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/'
   [junit4]   2> 654845 T1235 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/'
   [junit4]   2> 654902 T1207 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 654902 T1189 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 654902 T1250 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 654905 T1235 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 654931 T1207 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 654932 T1207 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 654933 T1189 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 654934 T1189 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 654934 T1235 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 654935 T1250 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 654935 T1235 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 654936 T1250 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 654938 T1207 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 654940 T1189 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 654941 T1235 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 654943 T1250 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 655272 T1189 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655272 T1189 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655273 T1189 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 655277 T1207 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655278 T1207 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655278 T1189 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 655278 T1207 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 655279 T1235 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655279 T1235 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655280 T1235 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 655280 T1189 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 655283 T1207 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 655284 T1235 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 655285 T1207 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 655287 T1235 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 655291 T1250 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655291 T1189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655291 T1250 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 655292 T1250 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 655294 T1189 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655296 T1207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655297 T1250 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 655297 T1189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655297 T1235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655298 T1189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655298 T1189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655299 T1189 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655299 T1207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655299 T1250 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 655299 T1189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655300 T1189 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655300 T1189 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 655300 T1235 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655300 T1189 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/data/
   [junit4]   2> 655301 T1189 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d0ed4e
   [junit4]   2> 655302 T1189 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/data
   [junit4]   2> 655302 T1207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655302 T1189 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/data/index/
   [junit4]   2> 655303 T1189 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 655303 T1235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655303 T1207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655303 T1207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655303 T1189 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1376931117323/nodes_used_collection_shard2_replica1/data/index
   [junit4]   2> 655304 T1235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655304 T1235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655303 T1207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655304 T1235 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655304 T1189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655305 T1207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655305 T1235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655305 T1235 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655305 T1189 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8153e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15e73a5),segFN=segments_1,generation=1}
   [junit4]   2> 655305 T1207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655306 T1189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655306 T1235 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 655306 T1207 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 655307 T1235 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/data/
   [junit4]   2> 655307 T1207 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/, dataDir=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/data/
   [junit4]   2> 655307 T1235 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d0ed4e
   [junit4]   2> 655307 T1207 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d0ed4e
   [junit4]   2> 655308 T1250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655308 T1207 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/data
   [junit4]   2> 655308 T1235 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/data
   [junit4]   2> 655309 T1207 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/data/index/
   [junit4]   2> 655309 T1189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 655309 T1207 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 655309 T1235 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/data/index/
   [junit4]   2> 655310 T1207 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1376931118692/nodes_used_collection_shard1_replica2/data/index
   [junit4]   2> 655310 T1189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 655310 T1207 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655310 T1235 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 655311 T1250 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 655310 T1189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 655311 T1235 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1376931133643/nodes_used_collection_shard2_replica2/data/index
   [junit4]   2> 655311 T1207 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@549f91 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6160a7),segFN=segments_1,generation=1}
   [junit4]   2> 655312 T1235 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655311 T1189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655312 T1207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655312 T1189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655312 T1235 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4636a1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e05e9f),segFN=segments_1,generation=1}
   [junit4]   2> 655313 T1235 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655313 T1189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 655313 T1250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655314 T1189 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655314 T1189 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655314 T1250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655315 T1250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655315 T1189 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 655315 T1207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 655316 T1235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 655315 T1250 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 655316 T1235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 655316 T1207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 655316 T1189 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 655317 T1207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 655317 T1250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 655317 T1250 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 655316 T1235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 655318 T1250 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 655317 T1207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655317 T1189 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 655318 T1189 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 655318 T1207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655318 T1250 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/
   [junit4]   2> 655318 T1235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655319 T1250 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d0ed4e
   [junit4]   2> 655319 T1207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 655319 T1189 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 655320 T1207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655320 T1189 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 655320 T1207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655321 T1207 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 655320 T1250 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data
   [junit4]   2> 655321 T1207 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 655319 T1235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655322 T1207 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 655322 T1207 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 655321 T1250 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index/
   [junit4]   2> 655321 T1189 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 655322 T1250 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 655322 T1207 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 655322 T1235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 655323 T1207 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 655323 T1235 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655323 T1207 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 655323 T1250 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index
   [junit4]   2> 655323 T1235 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655324 T1235 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 655324 T1250 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=44, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 655325 T1235 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 655324 T1189 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 655325 T1235 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 655325 T1235 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 655324 T1207 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 655326 T1235 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 655325 T1250 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fa5cce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ee15e8),segFN=segments_1,generation=1}
   [junit4]   2> 655326 T1235 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 655326 T1250 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655327 T1235 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 655327 T1189 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 655327 T1189 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 655328 T1207 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 655328 T1189 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=7.1796875, floorSegmentMB=0.833984375, forceMergeDeletesPctAllowed=15.618829176770085, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 655328 T1207 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 655328 T1189 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8153e9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15e73a5),segFN=segments_1,generation=1}
   [junit4]   2> 655329 T1207 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=7.1796875, floorSegmentMB=0.833984375, forceMergeDeletesPctAllowed=15.618829176770085, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 655328 T1235 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 655329 T1207 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@549f91 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6160a7),segFN=segments_1,generation=1}
   [junit4]   2> 655329 T1189 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655329 T1250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 655329 T1207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655330 T1250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 655330 T1189 oass.SolrIndexSearcher.<init> Opening Searcher@19d35c5 main
   [junit4]   2> 655331 T1250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 655330 T1207 oass.SolrIndexSearcher.<init> Opening Searcher@f69fe2 main
   [junit4]   2> 655331 T1250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655332 T1235 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 655332 T1250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 655332 T1235 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 655332 T1250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 655333 T1235 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=7.1796875, floorSegmentMB=0.833984375, forceMergeDeletesPctAllowed=15.618829176770085, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 655333 T1250 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655333 T1235 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4636a1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e05e9f),segFN=segments_1,generation=1}
   [junit4]   2> 655334 T1235 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 655333 T1261 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@f69fe2 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 655334 T1235 oass.SolrIndexSearcher.<init> Opening Searcher@fe7f99 main
   [junit4]   2> 655334 T1207 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
   [junit4]   2> 655335 T1207 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:56172/nzy/mn collection:nodes_used_collection shard:shard1
   [junit4]   2> 655334 T1250 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 655334 T1260 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@19d35c5 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 655335 T1250 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 655335 T1207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 655336 T1250 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 655336 T1189 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
   [junit4]   2> 655336 T1250 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 655337 T1250 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 655336 T1262 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@fe7f99 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 655337 T1250 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 655337 T1189 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:46646/nzy/mn collection:nodes_used_collection shard:shard2
   [junit4]   2> 655338 T1189 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 655338 T1250 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 655338 T1207 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
   [junit4]   2> 655338 T1250 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 655338 T1235 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
   [junit4]   2> 655339 T1235 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:39140/nzy/mn collection:nodes_used_collection shard:shard2
   [junit4]   2> 655339 T1235 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 655340 T1250 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 655342 T1250 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 655342 T1250 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 655342 T1250 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=7.1796875, floorSegmentMB=0.833984375, forceMergeDeletesPctAllowed=15.618829176770085, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 655343 T1250 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		comm

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

StateUpdater.run Starting to work on the main queue
   [junit4]   2> 732065 T1293 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 732065 T1293 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"nodes_used_collection_shard2_replica2",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39140_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39140/nzy/mn"}
   [junit4]   2> 732107 T1293 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"awholynewcollection_0_shard1_replica2",
   [junit4]   2> 	  "collection":"awholynewcollection_0",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39140_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:39140/nzy/mn"}
   [junit4]   2> 732152 T1293 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "core":"nodes_used_collection_shard1_replica1",
   [junit4]   2> 	  "collection":"nodes_used_collection",
   [junit4]   2> 	  "node_name":"127.0.0.1:42733_nzy%2Fmn",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42733/nzy/mn"}
   [junit4]   2> 732152 T1293 oasc.Overseer$ClusterStateUpdater.updateState shard=shard1 is already registered
   [junit4]   2> 732375 T1254 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> 733996 T1172 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
   [junit4]   2> 734063 T1172 oasc.SolrCore.close [nodes_used_collection_shard1_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@309556
   [junit4]   2> 734072 T1172 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 734073 T1172 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 734073 T1172 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 734074 T1172 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 734075 T1172 oasc.SolrCore.closeSearcher [nodes_used_collection_shard1_replica1] Closing main searcher on request.
   [junit4]   2> 734076 T1172 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 734076 T1172 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data;done=false>>]
   [junit4]   2> 734076 T1172 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data
   [junit4]   2> 734077 T1172 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index;done=false>>]
   [junit4]   2> 734077 T1172 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376931135376/nodes_used_collection_shard1_replica1/data/index
   [junit4]   2> 734079 T1293 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90238557226401804-127.0.0.1:42733_nzy%2Fmn-n_0000000004) am no longer a leader.
   [junit4]   2> 734095 T1254 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> 734096 T1254 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 734096 T1254 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 734119 T1172 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/nzy/mn,null}
   [junit4]   2> 734172 T1172 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 734174 T1172 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59900 59900
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=180F372952506007 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_AR -Dtests.timezone=US/Eastern -Dtests.file.encoding=UTF-8
   [junit4] ERROR    114s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_0
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([180F372952506007:99E9B931250F003B]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:424)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:318)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1571)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1585)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:481)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:152)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 734562 T1172 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene42: {}, docValues:{}, sim=DefaultSimilarity, locale=es_AR, timezone=US/Eastern
   [junit4]   2> NOTE: Linux 3.2.0-51-generic i386/Oracle Corporation 1.7.0_25 (32-bit)/cpus=8,threads=2,free=142880952,total=330760192
   [junit4]   2> NOTE: All tests run in this JVM: [TestDefaultSearchFieldResource, TestStressReorder, SuggesterWFSTTest, ChaosMonkeyNothingIsSafeTest, TestFastWriter, TestWordDelimiterFilterFactory, StatsComponentTest, OutputWriterTest, PreAnalyzedFieldTest, TestNumberUtils, TestRangeQuery, TermVectorComponentDistributedTest, DebugComponentTest, IndexSchemaRuntimeFieldTest, TimeZoneUtilsTest, TestMultiCoreConfBootstrap, TestFieldResource, RequiredFieldsTest, CachingDirectoryFactoryTest, TestQuerySenderListener, TestJmxIntegration, AssignTest, CoreAdminCreateDiscoverTest, TestOmitPositions, PluginInfoTest, TestSolrJ, TestRecovery, CustomCollectionTest, TestFieldCollectionResource, PrimUtilsTest, MinimalSchemaTest, UniqFieldsUpdateProcessorFactoryTest, TestRandomFaceting, StandardRequestHandlerTest, TestReload, NumericFieldsTest, TestFoldingMultitermQuery, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J1 in 114.08s, 1 test, 1 error <<< FAILURES!

[...truncated 647 lines...]
BUILD FAILED
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:375: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:450: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/var/lib/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 323 suites, 1376 tests, 1 error, 34 ignored (6 assumptions)

Total time: 54 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_25 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message