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 (64bit/jdk1.7.0_45) - Build # 8569 - Failure!
Date Fri, 13 Dec 2013 01:35:17 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/8569/
Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
some core start times did not change on reload

Stack Trace:
java.lang.AssertionError: some core start times did not change on reload
	at __randomizedtesting.SeedInfo.seed([A07758335BB9258B:2191D62B2CE645B7]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:770)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:196)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
	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:744)




Build Log:
[...truncated 10407 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> 412799 T818 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 412803 T818 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1386897483823
   [junit4]   2> 412804 T818 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 412804 T819 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 412904 T818 oasc.ZkTestServer.run start zk server on port:44730
   [junit4]   2> 412905 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 412985 T825 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5bca570c name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 412985 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 412985 T818 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 412990 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 412991 T827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5068c0f6 name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 412992 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 412992 T818 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 412995 T818 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 412998 T818 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 412999 T818 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 413002 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 413002 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 413006 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 413007 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 413009 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/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> 413010 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 413012 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 413013 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 413015 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 413016 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 413021 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 413022 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 413030 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 413030 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 413033 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 413034 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 413036 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 413037 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 413040 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 413040 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 413043 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 413044 T818 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 413048 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413049 T829 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f0a0a17 name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413050 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413050 T818 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 413055 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413057 T831 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63f7ffaa name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413057 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413058 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 413058 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 413062 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 413063 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 413066 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 413066 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 413069 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 413070 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 413072 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 413073 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 413076 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 413077 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 413085 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 413085 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 413088 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 413088 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 413093 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 413094 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 413097 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 413097 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 413100 T818 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 413101 T818 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 413174 T818 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 413178 T818 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40958
   [junit4]   2> 413179 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 413179 T818 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 413180 T818 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123
   [junit4]   2> 413180 T818 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/'
   [junit4]   2> 413197 T818 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solr.xml
   [junit4]   2> 413242 T818 oasc.CoreContainer.<init> New CoreContainer 327866467
   [junit4]   2> 413242 T818 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/]
   [junit4]   2> 413243 T818 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 413243 T818 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 413244 T818 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 413244 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 413244 T818 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 413245 T818 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 413245 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 413245 T818 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 413245 T818 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 413250 T818 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 413251 T818 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 413251 T818 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 413251 T818 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44730/solr
   [junit4]   2> 413251 T818 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 413252 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413254 T842 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e8d0165 name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413255 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413257 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413258 T844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7aa04a87 name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413259 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413260 T818 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 413263 T818 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 413266 T818 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 413267 T818 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40958_
   [junit4]   2> 413268 T818 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40958_
   [junit4]   2> 413271 T818 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 413281 T818 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 413288 T818 oasc.Overseer.start Overseer (id=90891713499955205-127.0.0.1:40958_-n_0000000000) starting
   [junit4]   2> 413290 T818 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 413293 T846 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 413294 T818 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 413296 T818 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 413297 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 413300 T845 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 413301 T818 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 413301 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 413303 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413304 T849 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ed49d9a name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413304 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413305 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 413307 T818 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 413391 T818 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 413394 T818 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48893
   [junit4]   2> 413394 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 413395 T818 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 413395 T818 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326
   [junit4]   2> 413395 T818 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/'
   [junit4]   2> 413411 T818 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solr.xml
   [junit4]   2> 413454 T818 oasc.CoreContainer.<init> New CoreContainer 1131206009
   [junit4]   2> 413454 T818 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/]
   [junit4]   2> 413456 T818 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 413456 T818 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 413456 T818 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 413456 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 413457 T818 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 413457 T818 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 413457 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 413457 T818 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 413458 T818 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 413462 T818 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 413463 T818 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 413463 T818 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 413463 T818 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44730/solr
   [junit4]   2> 413464 T818 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 413464 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413466 T860 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2df2e82e name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413467 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413470 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 413471 T862 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55a844b8 name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 413471 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 413474 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 414477 T818 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48893_
   [junit4]   2> 414478 T818 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48893_
   [junit4]   2> 414482 T862 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 414482 T844 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 414482 T849 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 414487 T818 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 414487 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 414556 T818 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 414558 T818 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34759
   [junit4]   2> 414559 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 414559 T818 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 414559 T818 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1386897485507
   [junit4]   2> 414559 T818 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1386897485507/'
   [junit4]   2> 414569 T818 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1386897485507/solr.xml
   [junit4]   2> 414611 T818 oasc.CoreContainer.<init> New CoreContainer 961288904
   [junit4]   2> 414611 T818 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1386897485507/]
   [junit4]   2> 414612 T818 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 414612 T818 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 414613 T818 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 414613 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 414613 T818 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 414613 T818 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 414614 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 414614 T818 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 414614 T818 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 414626 T818 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 414627 T818 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 414627 T818 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 414627 T818 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44730/solr
   [junit4]   2> 414627 T818 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 414628 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 414630 T874 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e994111 name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 414631 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 414633 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 414714 T876 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@586639da name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 414714 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 414720 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 415723 T818 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34759_
   [junit4]   2> 415724 T818 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34759_
   [junit4]   2> 415727 T862 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 415727 T844 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 415727 T876 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 415727 T849 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 415733 T818 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 415734 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 415811 T818 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 415813 T818 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44655
   [junit4]   2> 415814 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 415814 T818 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 415815 T818 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754
   [junit4]   2> 415815 T818 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/'
   [junit4]   2> 415825 T818 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/solr.xml
   [junit4]   2> 415863 T818 oasc.CoreContainer.<init> New CoreContainer 356606701
   [junit4]   2> 415863 T818 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/]
   [junit4]   2> 415864 T818 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 415864 T818 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 415865 T818 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 415865 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 415865 T818 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 415865 T818 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 415865 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 415866 T818 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 415866 T818 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 415869 T818 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 415870 T818 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 415870 T818 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 415870 T818 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44730/solr
   [junit4]   2> 415871 T818 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 415871 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 415873 T888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@779ba568 name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 415873 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 415876 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 415877 T890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5df2a3fa name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 415878 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 415882 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 416887 T818 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44655_
   [junit4]   2> 416888 T818 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44655_
   [junit4]   2> 416891 T862 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 416891 T844 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 416891 T849 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 416891 T890 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 416891 T876 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 416895 T818 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 416896 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 417011 T818 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 417013 T818 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38805
   [junit4]   2> 417014 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 417014 T818 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 417014 T818 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915
   [junit4]   2> 417014 T818 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/'
   [junit4]   2> 417025 T818 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solr.xml
   [junit4]   2> 417063 T818 oasc.CoreContainer.<init> New CoreContainer 1356772424
   [junit4]   2> 417063 T818 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/]
   [junit4]   2> 417064 T818 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 417064 T818 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 417064 T818 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 417065 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 417065 T818 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 417065 T818 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 417065 T818 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 417065 T818 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 417066 T818 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 417070 T818 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 417070 T818 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 417070 T818 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 417070 T818 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44730/solr
   [junit4]   2> 417071 T818 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 417071 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 417074 T902 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10d4bd88 name:ZooKeeperConnection Watcher:127.0.0.1:44730 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 417075 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 417077 T818 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 417079 T904 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15ce7b40 name:ZooKeeperConnection Watcher:127.0.0.1:44730/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 417079 T818 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 417083 T818 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 418086 T818 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38805_
   [junit4]   2> 418087 T818 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38805_
   [junit4]   2> 418090 T876 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418091 T844 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418091 T849 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418091 T862 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418091 T890 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418091 T904 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 418096 T818 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 418096 T818 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 418106 T857 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&wt=javabin&router.name=compositeId&action=CREATE&numShards=2&name=solrj_collection&version=2
   [junit4]   2> 418107 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418108 T846 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 418109 T846 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 418109 T846 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 418109 T846 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 418113 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418114 T845 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 418115 T845 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 418115 T845 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 418117 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418118 T876 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> 418118 T862 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> 418118 T890 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> 418118 T849 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> 418118 T904 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> 418119 T844 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> 418213 T846 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
   [junit4]   2> 418213 T846 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:44655_
   [junit4]   2> 418214 T846 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:38805_
   [junit4]   2> 418214 T846 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:40958_
   [junit4]   2> 418215 T846 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:48893_
   [junit4]   2> 418220 T884 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
   [junit4]   2> 418221 T897 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
   [junit4]   2> 418220 T839 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
   [junit4]   2> 418222 T856 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
   [junit4]   2> 418223 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418223 T884 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 418225 T897 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 418225 T839 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 418225 T856 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 418226 T845 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 418227 T845 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44655",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:44655_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 418229 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418230 T845 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:38805",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38805_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 418238 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418239 T845 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40958",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40958_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 418242 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418248 T845 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48893",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:48893_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 418251 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 418353 T876 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> 418353 T890 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> 418353 T849 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> 418353 T904 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> 418353 T862 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> 418353 T844 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> 419223 T884 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 419224 T884 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/solr.xml
   [junit4]   2> 419224 T884 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/solrj_collection_shard1_replica1
   [junit4]   2> 419225 T884 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 419225 T897 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 419225 T856 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 419225 T839 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 419226 T897 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solr.xml
   [junit4]   2> 419226 T839 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solr.xml
   [junit4]   2> 419225 T884 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 419227 T884 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 419227 T839 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1
   [junit4]   2> 419227 T839 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 419227 T897 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2
   [junit4]   2> 419226 T856 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solr.xml
   [junit4]   2> 419228 T839 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 419228 T839 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 419228 T897 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 419228 T884 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1386897486754/solrj_collection_shard1_replica1/'
   [junit4]   2> 419228 T856 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2
   [junit4]   2> 419229 T856 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 419229 T897 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 419230 T897 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 419230 T856 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 419231 T856 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 419232 T897 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/'
   [junit4]   2> 419235 T839 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/'
   [junit4]   2> 419235 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/'
   [junit4]   2> 419295 T897 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 419296 T884 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 419306 T839 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 419316 T856 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 419356 T897 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 419358 T897 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 419362 T884 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 419366 T884 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 419377 T856 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 419378 T897 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 419378 T856 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 419382 T884 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 419382 T839 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 419384 T839 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 419389 T856 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 419392 T839 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 419989 T839 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 419990 T839 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 419991 T839 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 420013 T839 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 420017 T897 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420020 T897 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420021 T839 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 420021 T897 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 420027 T897 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 420030 T897 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 420046 T897 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420047 T856 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420047 T856 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420047 T839 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420048 T856 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 420050 T897 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420059 T839 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420059 T897 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420061 T856 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 420061 T897 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420061 T897 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420062 T897 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420064 T897 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420064 T897 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420064 T839 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420064 T856 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 420064 T897 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 420065 T839 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420066 T839 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420066 T897 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/data/
   [junit4]   2> 420066 T839 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420067 T897 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69fca521
   [junit4]   2> 420068 T839 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420069 T839 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420069 T897 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/data
   [junit4]   2> 420069 T839 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 420069 T897 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 420069 T839 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/data/
   [junit4]   2> 420070 T897 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 420070 T839 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69fca521
   [junit4]   2> 420070 T897 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 420071 T897 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=17.5244140625, floorSegmentMB=0.9130859375, forceMergeDeletesPctAllowed=14.422216241999633, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2337679079953115
   [junit4]   2> 420071 T839 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/data
   [junit4]   2> 420072 T839 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 420072 T897 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e67d9bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@67f7b857),segFN=segments_1,generation=1}
   [junit4]   2> 420072 T839 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 420072 T897 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420073 T839 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1386897484123/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 420073 T839 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=17.5244140625, floorSegmentMB=0.9130859375, forceMergeDeletesPctAllowed=14.422216241999633, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2337679079953115
   [junit4]   2> 420074 T839 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2be22e4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2993cec),segFN=segments_1,generation=1}
   [junit4]   2> 420075 T839 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420076 T897 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 420077 T897 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 420077 T897 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 420078 T897 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420078 T897 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420078 T897 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 420079 T839 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 420079 T897 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420079 T839 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 420079 T897 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420080 T897 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 420080 T839 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 420080 T839 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420080 T897 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 420081 T839 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420081 T839 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 420081 T897 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 420082 T839 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420082 T897 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 420082 T897 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 420082 T839 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420087 T839 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 420084 T856 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420083 T884 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420088 T839 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 420083 T897 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 420089 T839 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 420089 T839 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 420089 T839 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 420090 T839 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 420090 T839 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 420091 T839 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 420088 T884 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 420091 T856 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420089 T897 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 420092 T884 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 420093 T897 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 420095 T897 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 420095 T839 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 420098 T897 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 420098 T839 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 420099 T839 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 420100 T839 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6485629229793444]
   [junit4]   2> 420101 T856 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420102 T856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420102 T856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420102 T856 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 420099 T897 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 420101 T839 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2be22e4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2993cec),segFN=segments_1,generation=1}
   [junit4]   2> 420099 T884 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 420104 T897 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6485629229793444]
   [junit4]   2> 420104 T839 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420103 T856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 420105 T856 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 420105 T856 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 420105 T856 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/data/
   [junit4]   2> 420105 T897 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e67d9bb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@67f7b857),segFN=segments_1,generation=1}
   [junit4]   2> 420106 T897 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420106 T897 oass.SolrIndexSearcher.<init> Opening Searcher@2fbf4283 main
   [junit4]   2> 420105 T839 oass.SolrIndexSearcher.<init> Opening Searcher@4e798e5c main
   [junit4]   2> 420106 T856 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@69fca521
   [junit4]   2> 420108 T856 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/data
   [junit4]   2> 420111 T856 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 420111 T856 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 420112 T911 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@4e798e5c main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 420112 T856 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1386897484326/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 420112 T856 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=17.5244140625, floorSegmentMB=0.9130859375, forceMergeDeletesPctAllowed=14.422216241999633, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2337679079953115
   [junit4]   2> 420113 T839 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 420113 T839 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:40958 collection:solrj_collection shard:shard2
   [junit4]   2> 420111 T884 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 420112 T910 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@2fbf4283 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 420115 T856 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e40dd98 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@386205a1),segFN=segments_1,generation=1}
   [junit4]   2> 420115 T856 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420116 T897 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 420116 T897 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:38805 collection:solrj_collection shard:shard1
   [junit4]   2> 420117 T839 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 420117 T897 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 420119 T856 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 420122 T856 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 420122 T856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 420123 T856 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420123 T856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 420123 T856 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 420124 T856 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420124 T856 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 420124 T856 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 420129 T856 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 420130 T856 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 420130 T856 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 420130 T856 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 420130 T856 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 420131 T856 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 420131 T856 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 420132 T856 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 420134 T839 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 420135 T856 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 420135 T856 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 420135 T897 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 420136 T856 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6485629229793444]
   [junit4]   2> 420136 T856 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1e40dd98 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@386205a1),segFN=segments_1,generation=1}
   [junit4]   2> 420136 T856 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 420137 T856 oass.SolrIndexSearcher.<init> Opening Searcher@4406c3d8 main
   [junit4]   2> 420139 T912 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@4406c3d8 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 420140 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 420140 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 420140 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 420140 T856 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
   [junit4]   2> 420140 T856 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:48893 collection:solrj_collection shard:shard2
   [junit4]   2> 420141 T839 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=-1
   [junit4]   2> 420141 T839 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
   [junit4]   2> 420142 T839 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3401 name=solrj_collection_shard2_replica1 org.apache.solr.core.SolrCore@78d5d457 url=http://127.0.0.1:40958/solrj_collection_shard2_replica1 node=127.0.0.1:40958_ C3401_STATE=coll:solrj_collection core:solrj_collection_shard2_replica1 props:{state=down, base_url=http://127.0.0.1:40958, core=solrj_collection_shard2_replica1, node_name=127.0.0.1:40958_}
   [junit4]   2> 420142 T839 C3401 P40958 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40958/solrj_collection_shard2_replica1/
   [junit4]   2> 420142 T845 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 420143 T897 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=-3
   [junit4]   2> 420143 T897 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Was waiting for replicas to come up, but they are taking too long - assuming they won't come back till later
   [junit4]   2> 420144 T897 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3402 name=solrj_collection_shard1_replica2 org.apache.solr.core.SolrCore@7cd8a7eb url=http://127.0.0.1:38805/solrj_collection_shard1_replica2 node=127.0.0.1:38805_ C3402_STATE=coll:solrj_collection core:solrj_collection_shard1_replica2 props:{state=down, base_url=http://127.0.0.1:38805, core=solrj_collection_shard1_replica2, node_name=127.0.0.1:38805_}
   [junit4]   2> 420144 T897 C3402 P38805 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38805/solrj_collection_shard1_replica2/
   [junit4]   2> 420144 T897 C3402 P38805 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:38805 START replicas=[http://127.0.0.1:44655/solrj_collection_shard1_replica1/] nUpdates=100
   [junit4]   2> 420143 T839 C3401 P40958 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica1 url=http://127.0.0.1:40958 START replicas=[http://127.0.0.1:48893/solrj_collection_shard2_replica2/] nUpdates=100
   [junit4]   2> 420145 T897 C3402 P38805 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard1_replica2 url=http://127.0.0.1:38805 DONE.  We have no versions.  sync failed.
   [junit4]   2> 420147 T897 C3402 P38805 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 420148 T897 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 420148 T897 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38805/solrj_collection_shard1_replica2/ shard1
   [junit4]   2> 420149 T897 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard1
   [junit4]   2> 420146 T839 C3401 P40958 oasu.PeerSync.sync PeerSync: core=solrj_collection_shard2_replica1 url=http://127.0.0.1:40958 DONE.  We have no versions.  sync failed.
   [junit4]   2> 420156 T839 C3401 P40958 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 420156 T839 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 420156 T839 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40958/solrj_collection_shard2_replica1/ shard2
   [junit4]   2> 420157 T839 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leaders/shard2
   [junit4]   2> 420148 T844 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 420159 T890 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> 420159 T844 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> 420159 T849 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> 420159 T876 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> 420159 T904 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> 420159 T862 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> ASYNC  NEW_CORE C3403 name=solrj_collection_shard2_replica2 org.apache.solr.core.SolrCore@e716244 url=http://127.0.0.1:48893/solrj_collection_shard2_replica2 node=127.0.0.1:48893_ C3403_STATE=coll:solrj_collection core:solrj_collection_shard2_replica2 props:{state=down, base_url=http://127.0.0.1:48893, core=solrj_collection_shard2_replica2, node_name=127.0.0.1:48893_}
   [junit4]   2> 420170 T858 C3403 P48893 oasc.SolrCore.execute [solrj_collection_shard2_replica2] webapp= path=/get params={getVersions=100&wt=javabin&distrib=false&qt=/get&version=2} status=0 QTime=1 
   [junit4]   2> 420177 T884 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 420178 T845 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 420179 T844 oasc.Distrib

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

0_shard3_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38805_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"awholynewcollection_0",
   [junit4]   2> 	  "numShards":"4",
   [junit4]   2> 	  "core_node_name":"core_node8"}
   [junit4]   2> 512030 T818 oasc.SolrCore.close [awholynewcollection_0_shard3_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7af0d4b6
   [junit4]   2> 512032 T904 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 512040 T818 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,transaction_logs_total_size=230,transaction_logs_total_number=1}
   [junit4]   2> 512041 T818 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 512041 T818 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 512041 T818 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 512042 T818 oasc.SolrCore.closeSearcher [awholynewcollection_0_shard3_replica1] Closing main searcher on request.
   [junit4]   2> 512042 T818 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 512043 T818 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data;done=false>>]
   [junit4]   2> 512043 T818 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data
   [junit4]   2> 512043 T818 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data/index [CachedDir<<refCount=0;path=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data/index;done=false>>]
   [junit4]   2> 512043 T818 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1386897487915/awholynewcollection_0_shard3_replica1/data/index
   [junit4]   2> 512067 T818 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 512119 T818 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 512121 T818 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44730 44730
   [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=A07758335BB9258B -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ru_RU -Dtests.timezone=Pacific/Enderbury -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 99.5s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: some core start times did not change on reload
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([A07758335BB9258B:2191D62B2CE645B7]:0)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:770)
   [junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:196)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:849)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 512304 T818 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 99509 T817 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> 513545 T904 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 513545 T904 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard3/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:252)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:249)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:93)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:138)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene46: {range_facet_si=PostingsFormat(name=NestedPulsing), multiDefault=PostingsFormat(name=NestedPulsing), id=PostingsFormat(name=MockSep), timestamp=PostingsFormat(name=NestedPulsing), other_tl1=PostingsFormat(name=Direct), a_si=PostingsFormat(name=Direct), range_facet_sl=PostingsFormat(name=MockSep), range_facet_l=PostingsFormat(name=NestedPulsing), text=Pulsing41(freqCutoff=13 minBlockSize=16 maxBlockSize=102), a_t=PostingsFormat(name=NestedPulsing), intDefault=PostingsFormat(name=Direct), _version_=PostingsFormat(name=Direct)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=ru_RU, timezone=Pacific/Enderbury
   [junit4]   2> NOTE: Linux 3.8.0-34-generic amd64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=8,threads=1,free=42798432,total=145502208
   [junit4]   2> NOTE: All tests run in this JVM: [DocumentAnalysisRequestHandlerTest, TestDFRSimilarityFactory, TestDynamicFieldCollectionResource, DirectUpdateHandlerTest, HighlighterConfigTest, DistanceFunctionTest, TestFieldCollectionResource, SpellCheckComponentTest, ZkNodePropsTest, TestCodecSupport, TestQueryTypes, CurrencyFieldXmlFileTest, TestBinaryResponseWriter, TestDynamicFieldResource, TestHashPartitioner, TestSolrJ, TestFuzzyAnalyzedSuggestions, IndexSchemaRuntimeFieldTest, TestPhraseSuggestions, CachingDirectoryFactoryTest, IndexBasedSpellCheckerTest, TestStressReorder, StatsComponentTest, LeaderElectionIntegrationTest, TestAtomicUpdateErrorCases, AddSchemaFieldsUpdateProcessorFactoryTest, TestStressRecovery, ChaosMonkeyNothingIsSafeTest, TestSchemaResource, CoreContainerCoreInitFailuresTest, PluginInfoTest, CurrencyFieldOpenExchangeTest, HdfsDirectoryTest, TestDistributedSearch, TestRecoveryHdfs, HdfsCollectionsAPIDistributedZkTest, TestRandomFaceting, HdfsUnloadDistributedZkTest, SignatureUpdateProcessorFactoryTest, HdfsRecoveryZkTest, TestCustomSort, NotRequiredUniqueKeyTest, CollectionsAPIDistributedZkTest]
   [junit4] Completed on J1 in 100.79s, 1 test, 1 failure <<< FAILURES!

[...truncated 729 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:439: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1307: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:940: There were test failures: 347 suites, 1516 tests, 1 failure, 34 ignored (6 assumptions)

Total time: 47 minutes 17 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_45 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message