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-trunk-Linux (32bit/jdk1.7.0_21) - Build # 5444 - Failure!
Date Wed, 01 May 2013 23:42:14 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5444/
Java: 32bit/jdk1.7.0_21 -client -XX:+UseConcMarkSweepGC

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

Error Message:
There are still nodes recoverying - waited for 230 seconds

Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
	at __randomizedtesting.SeedInfo.seed([EA84A3BAF4FCAB23:6B622DA283A3CB1F]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:511)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:145)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
	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:601)
	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:722)




Build Log:
[...truncated 9409 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.870; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.874; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.874; org.apache.solr.cloud.ZkTestServer; STARTING ZK TEST SERVER
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.875; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.975; org.apache.solr.cloud.ZkTestServer; start zk server on port:57007
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:07.976; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.048; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1ddf9c8 name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.048; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.049; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.057; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.058; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@166ed92 name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.058; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.059; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.061; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.064; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.067; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.071; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.072; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.081; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.082; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.085; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.086; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.089; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.089; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.092; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.093; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.095; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.096; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.100; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.101; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.106; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.107; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.109; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.110; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.209; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.213; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:38975
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.213; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.214; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.214; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.215; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.215; org.apache.solr.core.CoreContainer; New CoreContainer 2256238
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.216; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.216; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.276; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.277; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.278; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/collection1/conf
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.285; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/collection1/conf/xslt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.307; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/collection1/lib
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.308; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/collection1/lib/classes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.310; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/conf/core.properties, adding to cores
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.313; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.313; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.314; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.314; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.315; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.315; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.316; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.316; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.317; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.317; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.321; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.322; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:57007/solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.322; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.323; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.324; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@127389d name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.325; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.326; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.329; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.330; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1abd0ed name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.330; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.331; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.334; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.336; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.337; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38975_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.338; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:38975_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.341; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.344; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.345; org.apache.solr.cloud.Overseer; Overseer (id=89617288912961539-127.0.0.1:38975_-n_0000000000) starting
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.347; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.349; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.350; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.351; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.353; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.355; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.357; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.357; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.358; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.360; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.362; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.363; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@4654a8 name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.363; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.364; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.365; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.431; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.433; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:36266
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.434; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.434; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.434; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.435; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.435; org.apache.solr.core.CoreContainer; New CoreContainer 28691599
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.436; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.436; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.481; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.482; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.483; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/collection1/conf
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.488; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/collection1/conf/xslt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.504; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/collection1/lib
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.505; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/collection1/lib/classes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.507; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/conf/core.properties, adding to cores
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.509; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.509; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.510; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.510; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.510; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.511; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.511; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.512; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.512; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.512; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.515; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.516; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:57007/solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.516; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.517; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.518; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1e305c4 name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.518; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.520; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.522; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.523; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1ce38e8 name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.524; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:08.526; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.528; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36266_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.530; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:36266_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.532; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.532; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.532; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.535; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.536; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.536; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.602; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.604; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:43551
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.605; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.605; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.605; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.606; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.606; org.apache.solr.core.CoreContainer; New CoreContainer 21691403
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.607; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.607; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.655; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.656; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.657; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/collection1/conf
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.662; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/collection1/conf/xslt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.681; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/collection1/lib
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.682; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/collection1/lib/classes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.684; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/conf/core.properties, adding to cores
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.687; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.687; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.688; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.688; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.689; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.689; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.690; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.690; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.691; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.691; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.694; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.695; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:57007/solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.695; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.696; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.697; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@fc31e3 name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.698; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.699; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.711; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.712; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@13a4cec name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.713; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:09.715; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.718; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43551_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.719; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:43551_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.721; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.721; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.721; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.721; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.725; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.725; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.726; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.794; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.796; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:58439
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.797; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.797; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.797; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.798; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.798; org.apache.solr.core.CoreContainer; New CoreContainer 32574677
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.799; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.799; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.858; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.859; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.859; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/collection1/conf
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.864; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/collection1/conf/xslt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.883; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/collection1/lib
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.884; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/collection1/lib/classes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.885; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/conf/core.properties, adding to cores
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.888; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.888; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.888; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.889; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.889; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.889; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.890; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.890; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.891; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.891; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.894; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.894; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:57007/solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.895; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.896; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.897; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@39738b name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.897; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.898; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.901; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.902; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@c3a0e name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.902; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:10.905; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.907; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58439_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.908; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:58439_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.910; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.910; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.910; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.911; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.911; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.914; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.915; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.915; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.978; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.980; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:52366
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.980; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.981; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.981; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.982; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/solr.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.982; org.apache.solr.core.CoreContainer; New CoreContainer 6492053
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.982; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:11.983; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.027; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.028; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/collection1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.029; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/collection1/conf
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.034; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/collection1/conf/xslt
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.051; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/collection1/lib
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.052; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/collection1/lib/classes
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.053; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/conf/core.properties, adding to cores
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.055; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.056; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.056; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.057; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.057; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.057; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.058; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.058; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.058; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.059; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.062; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.062; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:57007/solr
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.063; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.064; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.065; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@76a224 name:ZooKeeperConnection Watcher:127.0.0.1:57007 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.065; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.066; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.069; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.070; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1f3bb62 name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.070; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:12.073; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.075; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52366_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.077; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:52366_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.079; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.079; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.079; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.079; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.079; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.080; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.083; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.084; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.084; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.087; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.091; org.apache.solr.handler.admin.CollectionsHandler; Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.092; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.093; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4:junit4]   1>   "operation":"createcollection",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "maxShardsPerNode":null,
[junit4:junit4]   1>   "createNodeSet":null,
[junit4:junit4]   1>   "name":"nodes_used_collection",
[junit4:junit4]   1>   "replicationFactor":"2"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.093; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:36266_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.094; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:38975_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.095; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:58439_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.095; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:43551_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.100; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.100; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.100; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.100; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.101; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.099; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.102; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.102; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.101; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.103; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.101; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.103; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.103; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.102; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.105; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.105; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.104; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.106; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.105; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.107; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.106; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.107; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.108; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.108; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.110; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.110; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.111; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.111; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.111; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.112; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.112; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.114; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.154; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.160; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.164; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.184; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.222; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.223; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.229; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.230; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.230; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.234; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.234; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.235; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.241; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.242; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.242; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.249; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.762; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.776; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.779; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.790; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.793; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.796; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.797; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.798; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.798; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.799; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.799; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.800; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.800; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.801; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.801; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.802; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.802; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.802; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.803; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.805; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@13c31e6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4d1057),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.805; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.807; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.807; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.808; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.808; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.809; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.809; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.809; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.810; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.810; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.813; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.815; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@742152 main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.816; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.816; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.817; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.821; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@742152 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.822; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.828; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.834; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.837; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.848; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.849; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.853; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.856; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.857; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.857; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.857; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.857; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.858; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.858; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.859; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.859; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.860; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.860; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.861; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.861; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.862; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.862; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.862; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.864; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c122f2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@10c5779),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.864; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.866; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.866; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.867; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.867; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.868; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.868; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.869; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.869; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.870; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.872; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.875; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@16c8b2a main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.875; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.876; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.876; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.877; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.881; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@16c8b2a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.882; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.883; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.885; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.887; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.887; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.887; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.888; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.889; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.889; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.889; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.890; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.890; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.891; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.891; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.892; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.892; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.894; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5ee959 lockFactory=org.apache.lucene.store.NativeFSLockFactory@503adb),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.894; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.896; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.896; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.897; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.897; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.898; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.898; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.899; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.899; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.900; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.902; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.904; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@136dc9f main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.905; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367451308117/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.906; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.906; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.910; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@136dc9f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.913; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.914; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.920; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.923; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.933; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.937; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.940; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.941; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.941; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.942; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.943; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.943; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.943; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.944; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.944; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.945; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.945; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.946; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:13.946; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.947; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.948; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@138ea81 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fc5f0d),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.948; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.950; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.951; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.951; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.952; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.952; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.953; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.953; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.954; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.954; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.957; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.959; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1b78a68 main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.960; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.960; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.961; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.965; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1b78a68 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:13.968; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.362; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.363; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:43551_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:43551"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.363; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection nodes_used_collection with numShards 2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.366; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:36266_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:36266"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.368; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:38975_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:38975"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.370; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:58439_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:58439"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.373; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.824; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.825; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:43551 collection:nodes_used_collection shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.826; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.830; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.832; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.885; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.885; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:36266 collection:nodes_used_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.886; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.891; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.893; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.914; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.915; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:38975 collection:nodes_used_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.969; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:14.970; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:58439 collection:nodes_used_collection shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.333; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.333; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.334; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:43551/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.334; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:43551 START replicas=[http://127.0.0.1:58439/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.335; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:43551 DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.335; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.335; org.apache.solr.cloud.ShardLeaderElectionContext; We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.336; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:43551/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.336; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.341; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.394; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.395; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.395; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:36266/nodes_used_collection_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.396; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:36266 START replicas=[http://127.0.0.1:38975/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.396; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:36266 DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.397; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.397; org.apache.solr.cloud.ShardLeaderElectionContext; We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.397; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:36266/nodes_used_collection_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.398; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.403; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.900; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.909; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.919; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:38975/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:36266/nodes_used_collection_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.919; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:38975
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.919; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.920; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.920; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.920; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.921; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.921; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.922; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2822 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.922; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.926; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:38975__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.943; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:43551/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:43551/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.944; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:43551
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.944; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.944; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.946; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.946; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2846 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.954; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:36266/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:36266/nodes_used_collection_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.954; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:36266
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.955; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.955; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.957; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.957; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2858 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.973; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:58439/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:43551/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.973; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:58439
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.974; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.974; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.975; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.975; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.975; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.976; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.976; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=2876 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.976; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.976; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.978; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.979; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.979; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=2822},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=2846},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=2858},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=2876},core=nodes_used_collection_shard2_replica1}}}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.980; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:58439__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.980; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/collections params={numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=2889 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.981; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.982; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.983; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@17770ba name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.983; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.984; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.986; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.987; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.988; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@ec5c3d name:ZooKeeperConnection Watcher:127.0.0.1:57007/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.988; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.989; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.994; org.apache.solr.handler.admin.CollectionsHandler; Creating Collection : numShards=2&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.994; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.996; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
[junit4:junit4]   1>   "operation":"createcollection",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "maxShardsPerNode":"1",
[junit4:junit4]   1>   "createNodeSet":null,
[junit4:junit4]   1>   "name":"awholynewcollection_0",
[junit4:junit4]   1>   "replicationFactor":"2"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.996; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:58439_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.996; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:43551_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.996; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:36266_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.997; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:52366_
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.998; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.998; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.998; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.998; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.999; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.999; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.000; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.999; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:15.998; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.001; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.000; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.000; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.002; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.001; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.003; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.002; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.002; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.004; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.003; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.005; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.005; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.005; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.006; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.007; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.007; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.008; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.008; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.009; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.009; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.009; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/'
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.040; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.053; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.059; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.063; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.081; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.083; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.087; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.113; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.115; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.119; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.126; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.128; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.133; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.135; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.135; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.141; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.669; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.675; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.678; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.688; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.691; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.694; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.695; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.696; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.696; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.696; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.697; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.697; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.698; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.698; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.698; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.699; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.700; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.700; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.700; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.701; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.702; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c5a266 lockFactory=org.apache.lucene.store.NativeFSLockFactory@23ab64),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.703; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.705; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.705; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.705; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.706; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.706; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.707; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.707; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.708; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.708; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.709; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.711; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.711; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.714; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@cda0de main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.714; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367451310728/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.722; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.723; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.727; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@cda0de main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.730; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.736; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.743; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.748; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.749; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.750; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.750; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.751; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.751; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.752; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.752; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.752; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.753; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.754; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.754; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.754; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.755; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.756; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@126e552 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ec24e),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.757; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.759; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.759; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.760; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.760; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.761; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.761; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.761; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.762; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.762; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.765; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.767; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1784980 main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.768; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367451308366/awholynewcollection_0_shard2_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.769; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.769; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.772; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica1] Registered new searcher Searcher@1784980 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.774; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.779; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.785; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.788; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.798; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.803; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.806; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.807; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.808; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.808; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.809; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.809; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.810; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.810; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.811; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.811; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.812; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.812; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.813; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.813; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.814; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@efc6b1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4ae0be),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.815; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.817; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.817; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.818; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.818; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.819; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.819; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.820; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.820; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.821; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.823; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.824; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.826; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@51f21d main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.827; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367451309539/awholynewcollection_0_shard1_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.828; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.828; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.832; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.833; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@51f21d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.835; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.837; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.847; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.854; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.858; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.860; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.860; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.860; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.861; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.862; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.862; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.863; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.863; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@b6e204
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.863; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.864; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.865; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-05-01 23:35:16.865; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.866; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.867; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7294bd lockFactory=org.apache.lucene.store.NativeFSLockFactory@114bb15),segFN=segments_1,generation=1}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.868; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.870; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.870; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.871; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.872; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.872; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.873; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.873; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.873; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.874; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.877; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.881; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1cfebb3 main
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.881; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.882; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.883; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.886; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica2] Registered new searcher Searcher@1cfebb3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:16.888; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.415; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.415; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:38975__nodes_used_collection_shard1_replica2",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard1_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:38975_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:38975"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.418; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:43551__nodes_used_collection_shard2_replica2",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:43551_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:43551"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.421; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:36266__nodes_used_collection_shard1_replica1",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:36266_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:36266"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.423; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:58439__nodes_used_collection_shard2_replica1",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:58439_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:58439"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.426; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"awholynewcollection_0_shard1_replica1",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:58439_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:58439"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.426; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection awholynewcollection_0 with numShards 2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.430; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"awholynewcollection_0_shard2_replica1",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:36266_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:36266"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.432; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"awholynewcollection_0_shard1_replica2",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:43551_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:43551"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.434; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"awholynewcollection_0_shard2_replica2",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:52366_",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:52366"}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.437; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.437; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.436; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.733; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.734; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:58439 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.737; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.742; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.744; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.775; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.776; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard2_replica1 address:http://127.0.0.1:36266 collection:awholynewcollection_0 shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.777; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.781; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.783; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=180000
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.837; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.837; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:43551 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.889; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.890; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard2_replica2 address:http://127.0.0.1:52366 collection:awholynewcollection_0 shard:shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.926; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:38975__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.927; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:38975__nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:38975_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2001 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.981; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:58439__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:17.982; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:58439__nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:58439_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.245; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.245; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.246; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:58439/awholynewcollection_0_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.247; org.apache.solr.update.PeerSync; PeerSync: core=awholynewcollection_0_shard1_replica1 url=http://127.0.0.1:58439 START replicas=[http://127.0.0.1:43551/awholynewcollection_0_shard1_replica2/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.247; org.apache.solr.update.PeerSync; PeerSync: core=awholynewcollection_0_shard1_replica1 url=http://127.0.0.1:58439 DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.248; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.248; org.apache.solr.cloud.ShardLeaderElectionContext; We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.249; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:58439/awholynewcollection_0_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.249; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.254; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.284; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.285; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.285; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:36266/awholynewcollection_0_shard2_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.286; org.apache.solr.update.PeerSync; PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:36266 START replicas=[http://127.0.0.1:52366/awholynewcollection_0_shard2_replica2/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.287; org.apache.solr.update.PeerSync; PeerSync: core=awholynewcollection_0_shard2_replica1 url=http://127.0.0.1:36266 DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.287; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.288; org.apache.solr.cloud.ShardLeaderElectionContext; We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.288; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:36266/awholynewcollection_0_shard2_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.288; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.294; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard2_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.947; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.960; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.961; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.961; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.960; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.960; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.960; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.961; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.961; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.993; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:43551/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:58439/awholynewcollection_0_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.994; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:43551
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.994; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.995; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.995; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:36266/awholynewcollection_0_shard2_replica1/ and leader is http://127.0.0.1:36266/awholynewcollection_0_shard2_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.995; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:52366/awholynewcollection_0_shard2_replica2/ and leader is http://127.0.0.1:36266/awholynewcollection_0_shard2_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.996; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard2_replica1 baseURL=http://127.0.0.1:36266
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.997; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.996; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard2_replica2 baseURL=http://127.0.0.1:52366
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.997; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard2_replica1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.998; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.999; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.999; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.999; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.999; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.000; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:18.999; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.001; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.001; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.002; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard2_replica2 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.005; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=awholynewcollection_0_shard2_replica2&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3008 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.000; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=awholynewcollection_0_shard1_replica2&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3002 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.002; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=awholynewcollection_0_shard2_replica1&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3004 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.006; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.002; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=recovering
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.007; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.011; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:58439/awholynewcollection_0_shard1_replica1/ and leader is http://127.0.0.1:58439/awholynewcollection_0_shard1_replica1/
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.011; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:52366__awholynewcollection_0_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.011; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:43551__awholynewcollection_0_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.011; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica1 baseURL=http://127.0.0.1:58439
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.013; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.013; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=active
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.015; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.015; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=awholynewcollection_0_shard1_replica1&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3018 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.016; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.018; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work/qnr-0000000002 state: SyncConnected type NodeDataChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.019; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.019; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000002 complete, response:{success={null={responseHeader={status=0,QTime=3008},core=awholynewcollection_0_shard2_replica2},null={responseHeader={status=0,QTime=3002},core=awholynewcollection_0_shard1_replica2},null={responseHeader={status=0,QTime=3004},core=awholynewcollection_0_shard2_replica1},null={responseHeader={status=0,QTime=3018},core=awholynewcollection_0_shard1_replica1}}}
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.020; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/collections params={numShards=2&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=3026 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.023; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.037; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.037; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=3 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.090; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.091; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=2 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.144; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.144; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=1 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.197; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.198; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=1 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.251; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.252; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=1 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.305; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:119)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4]   1> 	at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4]   1> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4]   1> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> 
[junit4:junit4]   1> INFO  - 2013-05-01 23:35:19.306; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] webapp= path=/select params={q=*:*&wt=javabin&version=2} status=503 QTime=1 
[junit4:junit4]   1> ERROR - 2013-05-01 23:35:19.360; org.apache.solr.common.SolrException; org.apache.solr.common.SolrException: no servers hosting shard: 
[junit4:junit4]   1> 	at org.apache.solr.handler.component.HttpShardHandler$1.call(HttpShardHandler.java:149)
[junit4:j

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

jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367451311918/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.126; org.apache.solr.cloud.Overseer$ClusterStateUpdater; According to ZK I (id=89617288912961548-127.0.0.1:52366_-n_0000000004) am no longer a leader.
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.147; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.200; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.202; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:57007 57007
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1367451307874
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=EA84A3BAF4FCAB23 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fi_FI -Dtests.timezone=America/Cambridge_Bay -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE  260s J0 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([EA84A3BAF4FCAB23:6B622DA283A3CB1F]:0)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
[junit4:junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:511)
[junit4:junit4]    > 	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:145)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.211; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> 260344 T3801 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 4 leaked thread(s).
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:28.339; org.apache.solr.cloud.LeaderElector$1; 
[junit4:junit4]   1> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4]   1> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   1> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   1> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   1> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   1> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:28.340; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:28.340; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:28.340; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:29.427; org.apache.solr.cloud.LeaderElector$1; 
[junit4:junit4]   1> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_0/leader_elect/shard2/election
[junit4:junit4]   1> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   1> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   1> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   1> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   1> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   1> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   1> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:29.427; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-05-01 23:39:29.428; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> WARN  - 2013-05-01 23:39:29.428; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=fi_FI, timezone=America/Cambridge_Bay
[junit4:junit4]   2> NOTE: Linux 3.2.0-40-generic i386/Oracle Corporation 1.7.0_21 (32-bit)/cpus=8,threads=1,free=214674120,total=518979584
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SynonymTokenizerTest, IndexSchemaTest, CacheHeaderTest, ShowFileRequestHandlerTest, TestExtendedDismaxParser, TestFieldResource, TestFastLRUCache, TestQuerySenderListener, SyncSliceTest, PrimUtilsTest, TestFieldTypeCollectionResource, ResourceLoaderTest, TestPseudoReturnFields, AlternateDirectoryTest, SOLR749Test, TestReversedWildcardFilterFactory, TestTrie, SearchHandlerTest, TestRealTimeGet, AutoCommitTest, TestFaceting, DistributedTermsComponentTest, AliasIntegrationTest, TestQueryUtils, SliceStateTest, TestStressVersions, TestManagedSchema, TestIBSimilarityFactory, LeaderElectionTest, TestGroupingSearch, JsonLoaderTest, FieldMutatingUpdateProcessorTest, QueryParsingTest, SuggesterFSTTest, OverseerTest, TestPHPSerializedResponseWriter, WordBreakSolrSpellCheckerTest, UpdateRequestProcessorFactoryTest, PeerSyncTest, BinaryUpdateRequestHandlerTest, TestFunctionQuery, TestSweetSpotSimilarityFactory, TestWriterPerf, TestStressRecovery, ReturnFieldsTest, AnalysisAfterCoreReloadTest, TestPerFieldSimilarity, TestFastWriter, ResponseLogComponentTest, ShardSplitTest, SimpleFacetsTest, LukeRequestHandlerTest, SliceStateUpdateTest, TestReplicationHandler, DirectSolrConnectionTest, TestManagedSchemaFieldResource, BadComponentTest, TestDynamicFieldResource, TestConfig, TestSerializedLuceneMatchVersion, TestCloudManagedSchemaAddField, ShardRoutingTest, BadCopyFieldTest, StatelessScriptUpdateProcessorFactoryTest, TestLRUCache, TestJoin, RecoveryZkTest, TestPhraseSuggestions, ChaosMonkeyNothingIsSafeTest, TestSolrQueryParser, TestSort, QueryEqualityTest, TestRandomDVFaceting, BasicDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed on J0 in 261.63s, 1 test, 1 failure <<< FAILURES!

[...truncated 434 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:378: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:358: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1240: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:884: There were test failures: 294 suites, 1220 tests, 1 failure, 13 ignored (7 assumptions)

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



Mime
View raw message