You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/05/02 21:29:10 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_21) - Build #
2782 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2782/
Java: 32bit/jdk1.7.0_21 -server -XX:+UseParallelGC
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([6009ACBD659BD061:E1EF22A512C4B05D]: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 9390 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 1> INFO - 2013-05-02 19:07:04.939; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:04.942; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4] 1> INFO - 2013-05-02 19:07:04.948; 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-02 19:07:04.949; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.046; org.apache.solr.cloud.ZkTestServer; start zk server on port:65196
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.048; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.056; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@2fdfd7 name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.056; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.056; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4] 1> WARN - 2013-05-02 19:07:05.065; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4] 1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e66a403800000, likely client has closed socket
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 1> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.067; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.070; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1e06521 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.071; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.071; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.079; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.085; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.090; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.098; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.099; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.113; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.113; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.122; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.123; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.131; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.131; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.139; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.140; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.148; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\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-02 19:07:05.149; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.157; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.157; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.163; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.164; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.171; org.apache.solr.cloud.AbstractZkTestCase; put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.172; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 1> WARN - 2013-05-02 19:07:05.181; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4] 1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e66a403800001, likely client has closed socket
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 1> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.668; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.677; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65203
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.678; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.678; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.678; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.679; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\solr.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.679; org.apache.solr.core.CoreContainer; New CoreContainer 4359293
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.680; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.680; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.780; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.782; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:05.783; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\collection1\conf
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.038; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\collection1\conf\xslt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.047; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\collection1\lib
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.050; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\collection1\lib\classes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.058; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\conf\core.properties, adding to cores
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.076; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.076; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.078; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.078; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.078; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.079; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.079; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.079; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.080; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.080; 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-02 19:07:06.090; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.091; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:65196/solr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.091; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.093; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.104; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@16123ce name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.106; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.111; 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-02 19:07:06.119; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.122; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@13166 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.123; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.127; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.135; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.142; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.145; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.148; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.154; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.164; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.169; org.apache.solr.cloud.Overseer; Overseer (id=89621897213378563-127.0.0.1:65203_pde%2Fr-n_0000000000) starting
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.176; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.184; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.186; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.191; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.195; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.202; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.204; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.205; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.205; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.209; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.222; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.230; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@14f0914 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.231; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.234; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.238; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.723; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.729; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65215
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.730; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.730; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.731; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.731; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\solr.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.732; org.apache.solr.core.CoreContainer; New CoreContainer 30952456
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.732; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.732; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.828; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.830; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:06.832; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\collection1\conf
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.075; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\collection1\conf\xslt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.083; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\collection1\lib
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.086; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\collection1\lib\classes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.093; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\conf\core.properties, adding to cores
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.112; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.113; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.113; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.114; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.114; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.114; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.115; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.115; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.115; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.116; 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-02 19:07:07.124; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.125; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:65196/solr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.125; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.127; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.142; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@b68726 name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.143; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.147; 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-02 19:07:07.155; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.159; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@794717 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.159; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:07.167; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.153; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.159; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.169; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.169; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.169; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.181; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.181; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.182; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.646; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.651; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65224
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.652; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.653; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.653; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.653; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\solr.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.654; org.apache.solr.core.CoreContainer; New CoreContainer 2923420
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.654; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.655; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.754; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.757; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:08.759; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\collection1\conf
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.002; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\collection1\conf\xslt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.011; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\collection1\lib
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.014; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\collection1\lib\classes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.021; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\conf\core.properties, adding to cores
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.039; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.039; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.039; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.040; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.040; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.040; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.040; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.041; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.041; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.041; 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-02 19:07:09.051; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.052; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:65196/solr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.052; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.054; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.068; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@339dad name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.069; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.073; 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-02 19:07:09.082; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.085; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@a9bc20 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.085; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:09.097; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.083; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.092; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.099; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.099; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.100; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.100; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.109; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.109; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.109; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.509; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.513; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65233
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.514; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.514; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.515; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.515; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\solr.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.516; org.apache.solr.core.CoreContainer; New CoreContainer 21921151
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.516; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.516; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.618; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.622; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.623; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\collection1\conf
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.814; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\collection1\conf\xslt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.821; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\collection1\lib
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.824; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\collection1\lib\classes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.830; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\conf\core.properties, adding to cores
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.845; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.845; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.845; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.846; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.846; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.846; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.846; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.846; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.847; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.847; 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-02 19:07:10.855; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.856; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:65196/solr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.856; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.858; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.873; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@109fbf0 name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.874; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.878; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 1> WARN - 2013-05-02 19:07:10.878; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4] 1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e66a403800009, likely client has closed socket
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 1> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.887; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.891; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@bf4cb9 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.891; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:10.900; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.885; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65233_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.895; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65233_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.908; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.908; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.910; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.912; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.913; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.930; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.930; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-05-02 19:07:11.931; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.360; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.364; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:65242
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.365; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.366; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.366; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.367; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\solr.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.368; org.apache.solr.core.CoreContainer; New CoreContainer 12909841
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.368; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.368; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.462; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.464; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\collection1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.465; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\collection1\conf
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.669; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\collection1\conf\xslt
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.676; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\collection1\lib
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.679; org.apache.solr.core.SolrCoreDiscoverer; Looking for cores in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\collection1\lib\classes
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.685; org.apache.solr.core.SolrCoreDiscoverer; Discovered properties file C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\conf\core.properties, adding to cores
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.703; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.703; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.704; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.704; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.705; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.705; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.706; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.706; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.707; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.707; 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-02 19:07:12.717; org.apache.solr.logging.LogWatcher; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.717; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:65196/solr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.718; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.719; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.735; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@4939b8 name:ZooKeeperConnection Watcher:127.0.0.1:65196 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.736; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.741; 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-02 19:07:12.749; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.752; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@626a68 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.753; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:12.762; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.749; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.762; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.777; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.777; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.779; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.780; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.780; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.781; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.798; org.apache.solr.servlet.SolrDispatchFilter; user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.799; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.800; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.811; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.819; 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-02 19:07:13.823; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.825; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.826; 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-02 19:07:13.826; 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:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.827; 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:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.827; 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:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.829; 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:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.831; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.831; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.832; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.832; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.832; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.833; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.833; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.832; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.833; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.835; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.835; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.835; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.837; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.836; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.835; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.838; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.838; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.839; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.840; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.840; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.841; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.843; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.844; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.844; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.848; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.849; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.852; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.854; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.855; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.855; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.861; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.869; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.972; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:13.993; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.043; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.063; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.071; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.087; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.142; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.144; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.149; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.159; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.208; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.236; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.258; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.263; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.406; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:14.411; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.387; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.516; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.596; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.601; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.715; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.725; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.729; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.734; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.739; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.766; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.773; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.773; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.779; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.782; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.787; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.789; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.788; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.793; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.794; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.799; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.799; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.801; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.798; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.802; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.803; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.803; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.806; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.806; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.807; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.807; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.807; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.808; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.809; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.810; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.810; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.810; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\index
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.811; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.812; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.812; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.813; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.813; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.813; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.814; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.810; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.817; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.818; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.818; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\index
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.820; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.821; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.821; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.824; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fbc686 lockFactory=org.apache.lucene.store.NativeFSLockFactory@230ab0),segFN=segments_1,generation=1}
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.824; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.824; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.825; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.825; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.826; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.826; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.827; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.827; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.828; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.828; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.829; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\index
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.834; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.842; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@132de96 lockFactory=org.apache.lucene.store.NativeFSLockFactory@de8ca3),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.842; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.842; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.843; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@19782ae lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ed4b45),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.843; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.843; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.844; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.844; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.845; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.845; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.845; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.846; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.846; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.848; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.848; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.849; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.849; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.850; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.850; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.850; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.851; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.851; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.859; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.859; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.860; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.861; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.861; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.861; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.862; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.862; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.863; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.870; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.870; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.871; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.874; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1a7e791 main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.874; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\nodes_used_collection_shard1_replica2\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.877; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@17186e4 main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.877; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.883; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.884; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.884; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.884; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\nodes_used_collection_shard2_replica1\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.885; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@c7665c main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.886; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\nodes_used_collection_shard1_replica1\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.886; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.887; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.888; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.888; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.890; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.888; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.891; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.897; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@1a7e791 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.898; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@17186e4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.900; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@c7665c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.901; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.902; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.902; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.902; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.903; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.904; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.904; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.904; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.905; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.906; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.906; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:15.906; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.908; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\index
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.914; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@153361c lockFactory=org.apache.lucene.store.NativeFSLockFactory@dda7cd),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.914; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.919; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.919; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.920; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.920; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.921; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.921; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.921; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.922; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.922; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.934; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.941; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@d5909d main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.942; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\nodes_used_collection_shard2_replica2\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.945; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.945; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.949; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@d5909d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:15.950; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.215; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.216; 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:65203_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65203/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.216; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection nodes_used_collection with numShards 2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.225; 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:65215_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65215/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.234; 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:65242_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65242/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.242; 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:65224_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65224/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:17.251; 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-02 19:07:17.253; 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-02 19:07:17.253; 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-02 19:07:17.253; 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-02 19:07:17.253; 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-02 19:07:17.254; 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-02 19:07:18.086; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.086; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:65203/pde/r collection:nodes_used_collection shard:shard2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.087; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.087; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:65242/pde/r collection:nodes_used_collection shard:shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.087; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.088; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:65215/pde/r collection:nodes_used_collection shard:shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.088; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.090; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.090; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.110; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.110; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:65224/pde/r collection:nodes_used_collection shard:shard2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.114; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.122; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.131; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.135; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.135; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.135; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:65215/pde/r/nodes_used_collection_shard1_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.137; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:65215/pde/r START replicas=[http://127.0.0.1:65242/pde/r/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.137; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:65215/pde/r DONE. We have no versions. sync failed.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.138; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.138; 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-02 19:07:18.138; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:65215/pde/r/nodes_used_collection_shard1_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.139; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.145; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.145; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.146; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:65203/pde/r/nodes_used_collection_shard2_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.146; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:65203/pde/r START replicas=[http://127.0.0.1:65224/pde/r/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.147; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:65203/pde/r DONE. We have no versions. sync failed.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.147; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.147; 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-02 19:07:18.148; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:65203/pde/r/nodes_used_collection_shard2_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.148; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.154; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] webapp=/pde/r path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.162; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] webapp=/pde/r path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.894; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.926; 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-02 19:07:18.928; 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-02 19:07:18.928; 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-02 19:07:18.928; 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-02 19:07:18.926; 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-02 19:07:18.926; 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-02 19:07:18.942; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65215/pde/r/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:65215/pde/r/nodes_used_collection_shard1_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.942; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:65215/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.942; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.943; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.946; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.948; 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=5116
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.997; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65203/pde/r/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:65203/pde/r/nodes_used_collection_shard2_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.997; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:65203/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.998; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4] 1> INFO - 2013-05-02 19:07:18.998; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.002; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.003; 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=5171
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.207; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65242/pde/r/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:65215/pde/r/nodes_used_collection_shard1_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.207; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:65242/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.207; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.207; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.209; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.209; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.210; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=recovering
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.211; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.214; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.215; 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=5384
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.229; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65242_pde%2Fr_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.233; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65224/pde/r/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:65203/pde/r/nodes_used_collection_shard2_replica1/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.233; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:65224/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.233; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.233; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.234; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.234; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.235; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.237; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.239; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.241; 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=5409
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.241; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.249; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65224_pde%2Fr_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.249; 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-02 19:07:19.253; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=5116},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=5171},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=5384},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=5409},core=nodes_used_collection_shard2_replica2}}}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.257; 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=5438
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.258; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.260; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.264; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1f06549 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.265; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.268; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.272; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.275; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.278; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@43dd88 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.278; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.281; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.292; org.apache.solr.handler.admin.CollectionsHandler; Creating Collection : numShards=1&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=3&action=CREATE&wt=javabin&version=2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.294; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.297; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.297; 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":"1",
[junit4:junit4] 1> "maxShardsPerNode":"1",
[junit4:junit4] 1> "createNodeSet":null,
[junit4:junit4] 1> "name":"awholynewcollection_0",
[junit4:junit4] 1> "replicationFactor":"3"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.298; 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:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.298; 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:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.298; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:65233_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.300; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.301; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.301; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.301; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.300; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.302; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.303; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.303; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.304; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.303; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.304; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.305; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.307; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.308; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.308; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.309; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.310; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.310; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.314; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.317; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.318; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.320; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.324; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.324; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.398; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.407; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.470; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.478; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.489; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.495; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.498; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.503; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.508; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.588; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.727; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:19.733; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.338; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.349; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.353; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.438; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.445; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.451; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.453; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.453; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.453; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.456; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.456; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.456; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.457; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.457; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.457; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.458; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.458; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.459; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.459; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\index
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.466; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@84d7db lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c28de6),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.466; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.469; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.469; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.471; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.471; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.472; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.472; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.472; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.473; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.473; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.486; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.490; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@cec5e9 main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.491; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_0_shard1_replica3\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.492; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.493; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.560; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Registered new searcher Searcher@cec5e9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.563; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.604; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.616; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.620; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.632; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.634; 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:65215_pde%2Fr_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:65215_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65215/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.656; 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:65203_pde%2Fr_nodes_used_collection_shard2_replica1",
[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_replica1",
[junit4:junit4] 1> "collection":"nodes_used_collection",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "node_name":"127.0.0.1:65203_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65203/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.666; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.677; 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:65242_pde%2Fr_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:65242_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65242/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.695; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.703; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.704; 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:65224_pde%2Fr_nodes_used_collection_shard2_replica2",
[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_replica2",
[junit4:junit4] 1> "collection":"nodes_used_collection",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "node_name":"127.0.0.1:65224_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65224/pde/r"}
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.707; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.707; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.707; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.710; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.710; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.711; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.711; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "numShards":"1",
[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_replica3",
[junit4:junit4] 1> "collection":"awholynewcollection_0",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "node_name":"127.0.0.1:65233_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65233/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.711; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection awholynewcollection_0 with numShards 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.711; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.712; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.712; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.714; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.715; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.715; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.715; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\index
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.725; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c4539d lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b77d5e),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.725; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.730; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.730; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.731; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.731; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.732; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.732; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.732; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.733; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.734; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.745; 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-02 19:07:20.745; 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-02 19:07:20.745; 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-02 19:07:20.746; 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-02 19:07:20.745; 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-02 19:07:20.746; 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-02 19:07:20.746; 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-02 19:07:20.746; 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-02 19:07:20.762; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.769; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@e6a864 main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.772; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_0_shard1_replica1\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.777; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.778; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.783; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@e6a864 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.787; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.846; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.857; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.862; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.884; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.899; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.906; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.908; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.909; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.909; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.911; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.911; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.911; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.912; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.912; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a2045
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.913; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.913; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.914; org.apache.solr.core.SolrCore; New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\index/
[junit4:junit4] 1> WARN - 2013-05-02 19:07:20.914; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.914; org.apache.solr.core.CachingDirectoryFactory; return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\index
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.922; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1cf739d lockFactory=org.apache.lucene.store.NativeFSLockFactory@6a4a0c),segFN=segments_1,generation=1}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.922; org.apache.solr.core.SolrDeletionPolicy; newest commit generation = 1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.926; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.927; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.927; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.928; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.928; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.930; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.930; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.931; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.931; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.943; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.950; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@b87cb5 main
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.951; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_0_shard1_replica2\data\tlog
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.953; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.953; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.958; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@b87cb5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:20.959; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.465; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:65242_pde%2Fr_nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.466; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:65242_pde%252Fr_nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:65242_pde%252Fr&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2236
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.465; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:65224_pde%2Fr_nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.466; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:65224_pde%252Fr_nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:65224_pde%252Fr&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2217
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.706; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica3
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.706; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica3 address:http://127.0.0.1:65233/pde/r collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.707; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.730; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.739; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.739; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.740; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.740; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.740; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/ has no replicas
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.741; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:21.741; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.420; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.421; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "numShards":"1",
[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:65224_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65224/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.442; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "numShards":"1",
[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:65203_pde%2Fr",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:65203/pde/r"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.467; 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-02 19:07:22.468; 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-02 19:07:22.468; 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-02 19:07:22.469; 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-02 19:07:22.469; 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-02 19:07:22.468; 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-02 19:07:22.468; 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-02 19:07:22.469; 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-02 19:07:22.478; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/ and leader is http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.478; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica3 baseURL=http://127.0.0.1:65233/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.479; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.479; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica3 state=active
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.484; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.487; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=1&shard=shard1&name=awholynewcollection_0_shard1_replica3&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3187
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.948; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.949; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:65224/pde/r collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.956; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65224/pde/r/awholynewcollection_0_shard1_replica1/ and leader is http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.957; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica1 baseURL=http://127.0.0.1:65224/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.957; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.957; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.958; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=awholynewcollection_0_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.959; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.959; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=recovering
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.959; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.962; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.963; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=1&shard=shard1&name=awholynewcollection_0_shard1_replica1&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3662
[junit4:junit4] 1> INFO - 2013-05-02 19:07:22.973; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65224_pde%2Fr_awholynewcollection_0_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.119; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.120; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:65203/pde/r collection:awholynewcollection_0 shard:shard1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.126; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:65203/pde/r/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:65233/pde/r/awholynewcollection_0_shard1_replica3/
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.127; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:65203/pde/r
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.127; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.127; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.128; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=awholynewcollection_0_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.129; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.129; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.130; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=recovering
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.132; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=1&shard=shard1&name=awholynewcollection_0_shard1_replica2&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3832
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.133; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: awholynewcollection_0
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.133; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.138; 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-02 19:07:23.146; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/collections params={numShards=1&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=3&action=CREATE&wt=javabin&version=2} status=0 QTime=3855
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.146; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:65203_pde%2Fr_awholynewcollection_0_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.147; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000002 complete, response:{success={null={responseHeader={status=0,QTime=3187},core=awholynewcollection_0_shard1_replica3},null={responseHeader={status=0,QTime=3662},core=awholynewcollection_0_shard1_replica1},null={responseHeader={status=0,QTime=3832},core=awholynewcollection_0_shard1_replica2}}}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.149; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> WARN - 2013-05-02 19:07:23.149; org.apache.zookeeper.server.NIOServerCnxn; caught end of stream exception
[junit4:junit4] 1> EndOfStreamException: Unable to read additional data from client sessionid 0x13e66a40380000e, likely client has closed socket
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 1> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 1> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.153; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.157; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1d07491 name:ZooKeeperConnection Watcher:127.0.0.1:65196/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.158; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.161; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.171; org.apache.solr.handler.admin.CollectionsHandler; Creating Collection : numShards=3&maxShardsPerNode=4&name=awholynewcollection_1&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.176; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.179; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000004 message:{
[junit4:junit4] 1> "operation":"createcollection",
[junit4:junit4] 1> "numShards":"3",
[junit4:junit4] 1> "maxShardsPerNode":"4",
[junit4:junit4] 1> "createNodeSet":null,
[junit4:junit4] 1> "name":"awholynewcollection_1",
[junit4:junit4] 1> "replicationFactor":"5"}
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.179; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard1_replica1 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.179; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard1_replica2 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.180; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard1_replica3 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.180; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard1_replica4 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:65233_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.180; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard1_replica5 as part of slice shard1 of collection awholynewcollection_1 on 127.0.0.1:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.181; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard2_replica1 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.181; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard2_replica2 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.182; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard2_replica3 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.183; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard1_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_1_shard1_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.186; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.186; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard2_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\awholynewcollection_1_shard2_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.187; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.185; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard2_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_1_shard2_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.188; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.188; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.184; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard1_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\awholynewcollection_1_shard1_replica3
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.189; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.184; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard1_replica5' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_1_shard1_replica5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.189; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.184; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard1_replica4' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_1_shard1_replica4
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.190; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.184; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard2_replica4 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:65233_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.183; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard1_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\awholynewcollection_1_shard1_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.192; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.191; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.193; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.190; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.195; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.189; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.197; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.188; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.198; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.198; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.188; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.187; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard2_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\awholynewcollection_1_shard2_replica3
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.200; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.199; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.200; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.201; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.195; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard2_replica4' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1367521630114\awholynewcollection_1_shard2_replica4
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.202; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.193; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.203; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.204; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.204; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.192; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.205; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.192; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard2_replica5 as part of slice shard2 of collection awholynewcollection_1 on 127.0.0.1:65224_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.206; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.206; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.207; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard3_replica1 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:65203_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.202; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.209; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.209; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard3_replica2 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:65242_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.201; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.210; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.210; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.201; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.211; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.211; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_1_shard3_replica3 as part of slice shard3 of collection awholynewcollection_1 on 127.0.0.1:65215_pde%2Fr
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.220; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.211; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.222; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard3_replica2' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1367521631945\awholynewcollection_1_shard3_replica2
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.222; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.219; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard3_replica1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1367521625182\awholynewcollection_1_shard3_replica1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.217; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard2_replica5' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_1_shard2_replica5
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.224; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.216; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.227; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.215; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.212; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.227; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.229; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.229; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.227; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.230; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.231; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.227; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_1_shard3_replica3' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1367521626239\awholynewcollection_1_shard3_replica3
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.232; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.233; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1367521628192\awholynewcollection_1_shard1_replica5\'
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.224; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.223; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.242; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.242; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_1
[junit4:junit4] 1> INFO - 2013-05-02 19:07:23.243; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\
[...truncated too long message...]
ZK
[junit4:junit4] 1> WARN - 2013-05-02 19:11:53.016; org.apache.solr.cloud.LeaderElector$1;
[junit4:junit4] 1> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_1/leader_elect/shard3/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> INFO - 2013-05-02 19:11:53.027; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/pde/r,null}
[junit4:junit4] 1> INFO - 2013-05-02 19:11:53.099; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4] 1> INFO - 2013-05-02 19:11:53.102; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:65196 65196
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-CollectionsAPIDistributedZkTest-1367521624946
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942\zookeeper\server1\data\version-2 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942\zookeeper\server1\data FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942\zookeeper\server1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942\zookeeper FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CollectionsAPIDistributedZkTest-1367521624942 FAILED !!!!!
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=6009ACBD659BD061 -Dtests.slow=true -Dtests.locale=ar_KW -Dtests.timezone=Africa/Djibouti -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 291s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([6009ACBD659BD061:E1EF22A512C4B05D]: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-02 19:11:55.558; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=ar_KW, timezone=Africa/Djibouti
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (32-bit)/cpus=2,threads=1,free=169541784,total=310050816
[junit4:junit4] 2> NOTE: All tests run in this JVM: [RequiredFieldsTest, CoreContainerCoreInitFailuresTest, ZkCLITest, TestRandomDVFaceting, LegacyHTMLStripCharFilterTest, DocValuesTest, TestPluginEnable, PolyFieldTest, SliceStateUpdateTest, TestAnalyzedSuggestions, TestSolrCoreProperties, QueryResultKeyTest, TestPhraseSuggestions, ShardRoutingCustomTest, WordBreakSolrSpellCheckerTest, SynonymTokenizerTest, XmlUpdateRequestHandlerTest, TestReplicationHandler, JSONWriterTest, OverseerCollectionProcessorTest, BasicDistributedZkTest, TestLFUCache, TestBinaryResponseWriter, TestMultiCoreConfBootstrap, TestStressVersions, TestSuggestSpellingConverter, LeaderElectionTest, TestStressReorder, ChaosMonkeySafeLeaderTest, BadCopyFieldTest, TestIBSimilarityFactory, DefaultValueUpdateProcessorTest, TestBadConfig, TestCloudManagedSchemaAddField, JsonLoaderTest, IndexSchemaRuntimeFieldTest, QueryEqualityTest, RegexBoostProcessorTest, FileBasedSpellCheckerTest, StatelessScriptUpdateProcessorFactoryTest, SolrCoreTest, CircularListTest, TestCoreDiscovery, SystemInfoHandlerTest, TestLuceneMatchVersion, SpellingQueryConverterTest, TestComponentsName, TestElisionMultitermQuery, TestBM25SimilarityFactory, TestSolrQueryParser, TestSolrXMLSerializer, TestWordDelimiterFilterFactory, TestCloudManagedSchema, TestConfig, SolrIndexConfigTest, SuggesterWFSTTest, ShowFileRequestHandlerTest, DistributedSpellCheckComponentTest, TestTrie, ResourceLoaderTest, URLClassifyProcessorTest, TestFaceting, XsltUpdateRequestHandlerTest, DocValuesMultiTest, UniqFieldsUpdateProcessorFactoryTest, TestJmxMonitoredMap, TestSweetSpotSimilarityFactory, TestCodecSupport, TestCSVLoader, ClusterStateTest, TestUpdate, DistributedTermsComponentTest, TestStressLucene, TestUniqueKeyFieldResource, IndexBasedSpellCheckerTest, ResponseLogComponentTest, TestSurroundQueryParser, SliceStateTest, TestQuerySenderNoQuery, TestRemoteStreaming, UpdateRequestProcessorFactoryTest, MinimalSchemaTest, SolrIndexSplitterTest, SolrCoreCheckLockOnStartupTest, QueryElevationComponentTest, HardAutoCommitTest, PrimitiveFieldTypeTest, SolrPluginUtilsTest, FieldAnalysisRequestHandlerTest, TestDFRSimilarityFactory, BadComponentTest, BasicFunctionalityTest, TestSolrQueryParserResource, UnloadDistributedZkTest, TestSolrQueryParserDefaultOperatorResource, TestDocSet, DebugComponentTest, OpenExchangeRatesOrgProviderTest, MultiTermTest, TestExtendedDismaxParser, LeaderElectionIntegrationTest, TestSchemaResource, TestAtomicUpdateErrorCases, TestRecovery, LoggingHandlerTest, SolrRequestParserTest, TestArbitraryIndexDir, AnalysisAfterCoreReloadTest, SpatialFilterTest, ExternalFileFieldSortTest, TestManagedSchemaFieldResource, ZkControllerTest, TestReversedWildcardFilterFactory, DateMathParserTest, TestHashPartitioner, CurrencyFieldXmlFileTest, SOLR749Test, HighlighterConfigTest, TestStressRecovery, TestCSVResponseWriter, TestLazyCores, SampleTest, TestSolrIndexConfig, DocumentBuilderTest, SimplePostToolTest, TestPropInjectDefaults, NotRequiredUniqueKeyTest, PeerSyncTest, AutoCommitTest, TestFoldingMultitermQuery, TestDocumentBuilder, TestPerFieldSimilarity, ChaosMonkeyShardSplitTest, TestFastWriter, TestSolrDeletionPolicy2, TestFastOutputStream, TestSearchPerf, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed in 290.65s, 1 test, 1 failure <<< FAILURES!
[...truncated 467 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:378: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:358: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1240: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:884: There were test failures: 294 suites, 1220 tests, 1 failure, 18 ignored (12 assumptions)
Total time: 67 minutes 4 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_21 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure