[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_21) - Build # 5304 - Failure!

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_21) - Build # 5304 - Failure!

Policeman Jenkins Server-2
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5304/
Java: 32bit/jdk1.7.0_21 -client -XX:+UseSerialGC

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([8ACBD6D7FB3B561A:B2D58CF8C643626]: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:509)
        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 9383 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.625; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /v_lz/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.628; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.629; 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-04-23 04:01:46.629; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.729; org.apache.solr.cloud.ZkTestServer; start zk server on port:38540
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.732; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.945; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@a66bdb name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.945; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.946; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.954; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.964; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1da2473 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.965; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.966; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.971; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.976; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.980; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.984; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:46.984; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.244; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.245; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.935; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.936; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.955; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.956; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.975; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:47.976; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.386; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.387; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.392; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.393; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.399; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.400; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.404; org.apache.solr.cloud.AbstractZkTestCase; put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.404; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.481; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.485; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:56844
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.486; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.486; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.486; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.487; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.487; org.apache.solr.core.CoreContainer; New CoreContainer 31710859
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.488; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.488; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.537; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.538; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.538; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.539; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.539; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.539; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.540; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.540; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.540; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.541; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.544; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.545; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:38540/solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.545; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.546; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.549; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1d45422 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.549; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.551; 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-04-23 04:01:48.554; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.556; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1649b41 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.556; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.558; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.560; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.567; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.569; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56844_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.570; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:56844_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.573; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.578; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.584; org.apache.solr.cloud.Overseer; Overseer (id=89567376613834755-127.0.0.1:56844_v_lz-n_0000000000) starting
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.587; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.591; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.592; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.594; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.596; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.609; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.609; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.610; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.610; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.614; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.618; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.621; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@251cd9 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.622; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.624; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.626; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.707; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.715; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:44705
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.716; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.716; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.717; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.717; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.718; org.apache.solr.core.CoreContainer; New CoreContainer 26541407
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.719; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.719; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.782; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.783; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.783; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.784; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.784; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.784; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.785; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.785; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.785; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.786; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.789; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.790; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:38540/solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.791; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.791; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.794; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@111d2b5 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.794; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.796; 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-04-23 04:01:48.800; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.801; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@16f33eb name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.802; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:48.810; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.822; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44705_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.824; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:44705_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.827; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.827; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.827; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.838; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.839; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.840; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.913; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.915; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:34584
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.916; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.916; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.916; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.917; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.917; org.apache.solr.core.CoreContainer; New CoreContainer 14949800
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.918; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.918; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.968; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.968; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.969; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.969; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.969; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.970; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.970; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.970; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.971; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.971; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.974; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.975; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:38540/solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.975; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.976; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.977; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1a8a1e5 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.979; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.981; 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-04-23 04:01:49.984; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.985; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1f3e788 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.985; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:49.988; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.991; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34584_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.994; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:34584_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.999; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.999; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.999; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:50.999; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.007; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.008; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.009; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.097; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.099; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:60675
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.099; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.099; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.100; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.100; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.101; org.apache.solr.core.CoreContainer; New CoreContainer 25636524
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.101; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.102; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.152; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.152; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.153; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.153; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.153; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.154; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.154; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.155; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.155; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.155; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.159; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.159; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:38540/solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.159; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.160; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.161; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@11c6c45 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.162; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.163; 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-04-23 04:01:51.167; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.168; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1ff0a67 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.169; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:51.171; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.174; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60675_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.177; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:60675_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.181; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.182; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.182; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.182; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.182; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.190; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.191; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.191; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.278; org.eclipse.jetty.server.Server; jetty-8.1.10.v20130312
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.280; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:47859
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.281; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.281; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.281; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.282; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.282; org.apache.solr.core.CoreContainer; New CoreContainer 27821992
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.283; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.283; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.336; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.336; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.337; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.337; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.337; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.338; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.338; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.339; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.339; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.339; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.342; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.343; org.apache.solr.core.ZkContainer; Zookeeper client=127.0.0.1:38540/solr
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.343; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.344; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.345; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@8bc8a9 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.346; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.348; 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-04-23 04:01:52.351; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.353; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@10cd3d5 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.353; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:52.356; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.359; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47859_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.361; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:47859_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.367; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.376; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.377; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.378; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.383; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.390; 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-04-23 04:01:53.392; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.394; 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-04-23 04:01:53.395; 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:47859_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.396; 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:56844_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.397; 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:44705_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.398; 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:60675_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.399; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.400; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.400; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.402; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.400; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.421; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.402; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.401; org.apache.solr.core.CoreContainer; Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.424; org.apache.solr.cloud.ZkController; Check for collection zkNode:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.423; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.425; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.423; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.421; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.427; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.427; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.426; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.428; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.427; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.431; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.432; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.432; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.432; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.434; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.435; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.437; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.438; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.442; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.442; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.443; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.443; org.apache.solr.cloud.ZkController; Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.444; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.446; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.494; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.499; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.506; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.507; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.558; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.560; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.565; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.572; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.573; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.587; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.589; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.591; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.594; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.596; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.597; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:53.602; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.311; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.324; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.328; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.328; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.331; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.335; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.339; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.340; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.341; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.341; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.344; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.346; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.350; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.350; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.352; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.352; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.353; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.353; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.354; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.355; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.361; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.362; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.362; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.363; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.363; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.364; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.365; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.365; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.366; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.366; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.367; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.367; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.368; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.370; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.370; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.370; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b446a5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1560c71),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.371; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.370; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.373; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.373; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.373; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.375; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.375; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.376; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.377; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.376; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.377; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.378; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.378; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.378; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.378; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.378; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.380; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.379; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.379; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.381; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.380; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.382; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.382; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.383; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.383; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.382; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.383; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.383; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.383; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.384; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.384; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.385; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.385; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.386; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.386; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.387; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.388; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.387; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.388; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.388; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@120b75f lockFactory=org.apache.lucene.store.NativeFSLockFactory@2c6f9),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.390; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.389; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.390; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5e599b main
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.390; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.390; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.392; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.392; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.391; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.391; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.393; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.393; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.395; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.395; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4cfd76 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b78a09),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.396; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.394; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.396; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.397; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.396; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.395; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.397; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.396; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.399; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.398; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.400; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.400; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.400; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.401; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.402; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.403; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.401; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.404; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@5e599b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.403; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.404; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.405; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.406; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:54.405; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.406; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.406; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.406; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@3cd8a3 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.407; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.407; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.408; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.408; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.410; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.410; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.410; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.410; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@18bb27f lockFactory=org.apache.lucene.store.NativeFSLockFactory@ce7e09),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.412; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.413; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1d9ff78 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.413; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.414; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.414; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.415; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@3cd8a3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.414; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.416; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.417; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.417; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.415; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.417; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.418; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.419; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.420; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.420; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.422; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@1d9ff78 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.424; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.424; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.427; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1132c44 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.428; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.428; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.429; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.432; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@1132c44 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.434; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.618; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.619; 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:56844_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:56844/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.619; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection nodes_used_collection with numShards 2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.622; 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:60675_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:60675/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.626; 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:47859_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:47859/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.629; 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:44705_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:44705/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:54.635; 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-04-23 04:01:54.635; 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-04-23 04:01:54.635; 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-04-23 04:01:54.635; 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-04-23 04:01:54.635; 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-04-23 04:01:54.635; 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-04-23 04:01:55.408; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.409; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:56844/v_lz collection:nodes_used_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.411; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.419; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.420; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:60675/v_lz collection:nodes_used_collection shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.421; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.421; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.425; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.426; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.427; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:47859/v_lz collection:nodes_used_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.431; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.435; org.apache.solr.core.CoreContainer; registering core: nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.436; org.apache.solr.cloud.ShardLeaderElectionContext; Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.436; org.apache.solr.cloud.ZkController; Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:44705/v_lz collection:nodes_used_collection shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.926; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.927; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.928; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:56844/v_lz/nodes_used_collection_shard1_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.929; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:56844/v_lz START replicas=[http://127.0.0.1:47859/v_lz/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.930; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:56844/v_lz DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.930; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.931; 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-04-23 04:01:55.932; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:56844/v_lz/nodes_used_collection_shard1_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.933; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.938; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.939; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.939; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:60675/v_lz/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.940; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:60675/v_lz START replicas=[http://127.0.0.1:44705/v_lz/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.941; org.apache.solr.update.PeerSync; PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:60675/v_lz DONE.  We have no versions.  sync failed.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.943; org.apache.solr.cloud.SyncStrategy; Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.944; 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-04-23 04:01:55.945; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:60675/v_lz/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.943; org.apache.solr.core.SolrCore; [nodes_used_collection_shard1_replica1] webapp=/v_lz path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.946; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:55.954; org.apache.solr.core.SolrCore; [nodes_used_collection_shard2_replica1] webapp=/v_lz path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.144; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.176; 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-04-23 04:01:56.176; 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-04-23 04:01:56.176; 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-04-23 04:01:56.176; 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-04-23 04:01:56.177; 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-04-23 04:01:56.177; 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-04-23 04:01:56.193; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:56844/v_lz/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:56844/v_lz/nodes_used_collection_shard1_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.194; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:56844/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.194; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.194; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.196; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.198; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.199; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.201; 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=2802
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.206; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:60675/v_lz/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:60675/v_lz/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.207; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:60675/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.208; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.208; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.211; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.213; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.216; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.218; 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=2817
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.433; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:47859/v_lz/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:56844/v_lz/nodes_used_collection_shard1_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.433; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:47859/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.434; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.434; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.435; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.435; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.435; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.436; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.437; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.437; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.439; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.439; 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=3039
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.443; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:44705/v_lz/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:60675/v_lz/nodes_used_collection_shard2_replica2/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.443; org.apache.solr.cloud.ZkController; No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:44705/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.443; org.apache.solr.cloud.ZkController; Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.444; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.444; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:47859_v_lz_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.445; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.444; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.445; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.445; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.446; org.apache.solr.cloud.ZkController; publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.447; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.448; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.449; 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=3049
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.449; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.451; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:44705_v_lz_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.493; 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-04-23 04:01:56.495; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.495; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=2802},core=nodes_used_collection_shard1_replica2,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml},null={responseHeader={status=0,QTime=2817},core=nodes_used_collection_shard2_replica2,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml},null={responseHeader={status=0,QTime=3039},core=nodes_used_collection_shard1_replica1,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml},null={responseHeader={status=0,QTime=3049},core=nodes_used_collection_shard2_replica1,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml}}}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.497; 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=3107
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.497; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.499; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.501; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@be142e name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.501; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.503; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.507; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.509; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.511; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@a3673f name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.512; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.514; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.522; org.apache.solr.handler.admin.CollectionsHandler; Creating Collection : numShards=1&maxShardsPerNode=2&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.525; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.527; 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":"2",
[junit4:junit4]   1>   "createNodeSet":null,
[junit4:junit4]   1>   "name":"awholynewcollection_0",
[junit4:junit4]   1>   "replicationFactor":"5"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.527; 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:47859_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.528; 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:60675_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.528; 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:34584_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.529; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:44705_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.529; org.apache.solr.cloud.OverseerCollectionProcessor; Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:56844_v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.530; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.531; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.530; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.532; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.533; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.530; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.534; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.535; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.535; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.532; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.532; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.531; org.apache.solr.core.CoreContainer; Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.538; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.538; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.538; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.537; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.541; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.541; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.541; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.539; org.apache.solr.cloud.ZkController; Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.544; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.544; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.542; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.546; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.546; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.546; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.550; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.551; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.551; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.550; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.554; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.552; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.555; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.554; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.558; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.558; org.apache.solr.cloud.ZkController; Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.556; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.559; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.561; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/'
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.633; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.634; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.654; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.654; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.663; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.722; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.723; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.729; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.739; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.740; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.742; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.744; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.745; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.746; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.748; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.749; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.758; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.771; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.773; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:56.779; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.586; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.595; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.598; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.619; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.622; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.626; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.627; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.628; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.629; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.631; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.633; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.636; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.637; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.648; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.649; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.650; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.651; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.651; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.652; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.653; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.653; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.655; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.655; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.655; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.653; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.656; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.655; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.658; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.658; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.658; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data/index/
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.659; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.660; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.662; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@130c31c lockFactory=org.apache.lucene.store.NativeFSLockFactory@8a2300),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.662; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.662; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.664; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.665; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.665; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.665; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.666; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.667; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.665; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.667; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.668; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.669; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.670; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.670; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.670; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.670; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.672; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.673; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.673; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.674; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.674; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.674; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.675; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.674; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.676; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.675; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.678; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.678; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@c9a303 main
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.679; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.679; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.678; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.679; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.680; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica5] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.680; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.679; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.682; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.682; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.679; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/awholynewcollection_0_shard1_replica3/data/tlog
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.683; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.684; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.681; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica4] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.681; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.685; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.685; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.685; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.684; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.684; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.683; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.687; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.686; 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:56844_v_lz_nodes_used_collection_shard1_replica2",
[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_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:56844_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:56844/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.686; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.686; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.689; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.688; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.687; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.690; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.690; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.692; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.689; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data/index/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.689; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data/index/
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.693; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica4] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.694; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.695; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica3] Registered new searcher Searcher@c9a303 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.695; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1c62a27 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1688ce8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.696; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.697; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.692; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.698; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.692; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data/index/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.692; 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:60675_v_lz_nodes_used_collection_shard2_replica2",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica2",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:60675_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:60675/v_lz"}
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.698; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.698; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.698; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.693; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica5] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.700; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.700; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.702; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.699; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.702; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.702; 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:47859_v_lz_nodes_used_collection_shard1_replica1",
[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_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:47859_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:47859/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.702; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.701; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.704; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b89ab8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@557d3b),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.704; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.703; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.706; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.707; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.707; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@d8fa7c lockFactory=org.apache.lucene.store.NativeFSLockFactory@10f155e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.708; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.706; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@148aa44
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.705; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.709; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.707; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.712; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.711; 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:44705_v_lz_nodes_used_collection_shard2_replica1",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "shard_state":"active",
[junit4:junit4]   1>   "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4]   1>   "collection":"nodes_used_collection",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:44705_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:44705/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.711; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.711; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.714; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.713; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.713; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.716; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> WARN  - 2013-04-23 04:01:57.715; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.715; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.718; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.717; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.717; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.716; 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:34584_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:34584/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.720; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.721; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.718; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.721; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.720; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1327eb9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b34782),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.723; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.720; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection awholynewcollection_0 with numShards 1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.723; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.722; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.724; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.724; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.725; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.726; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.727; 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-04-23 04:01:57.725; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.728; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.728; 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-04-23 04:01:57.728; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.728; 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-04-23 04:01:57.727; 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-04-23 04:01:57.727; 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-04-23 04:01:57.727; 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-04-23 04:01:57.727; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.727; 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-04-23 04:01:57.727; 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-04-23 04:01:57.731; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1444cf2 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.729; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1af5e94 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.729; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.733; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/awholynewcollection_0_shard1_replica4/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.732; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/awholynewcollection_0_shard1_replica2/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.734; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.732; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.734; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.734; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.733; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.735; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.735; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.736; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.737; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.738; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.748; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.750; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.749; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica4] Registered new searcher Searcher@1af5e94 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.749; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@1444cf2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.748; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.752; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@5bd898 main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.750; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.752; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/awholynewcollection_0_shard1_replica5/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.752; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.753; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.754; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.755; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.757; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@d37f1a main
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.758; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.758; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica5] Registered new searcher Searcher@5bd898 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.758; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.759; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.759; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica5 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.762; org.apache.solr.core.SolrCore; [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@d37f1a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:57.764; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.448; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:47859_v_lz_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.449; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:47859_v_lz_nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:47859_v_lz&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2005
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.453; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:44705_v_lz_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.454; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:44705_v_lz_nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:44705_v_lz&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.698; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica3
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.699; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica3 address:http://127.0.0.1:34584/v_lz collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.701; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.711; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.715; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.716; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.716; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.717; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.718; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.719; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:58.720; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.260; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.261; 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:60675_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:60675/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.268; 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_replica4",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:44705_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:44705/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.272; 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_replica5",
[junit4:junit4]   1>   "collection":"awholynewcollection_0",
[junit4:junit4]   1>   "shard_range":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:56844_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:56844/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.277; 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:47859_v_lz",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:47859/v_lz"}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.292; 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-04-23 04:01:59.293; 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-04-23 04:01:59.292; 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-04-23 04:01:59.292; 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-04-23 04:01:59.292; 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-04-23 04:01:59.292; 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-04-23 04:01:59.293; 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-04-23 04:01:59.293; 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-04-23 04:01:59.330; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/ and leader is http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.331; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica3 baseURL=http://127.0.0.1:34584/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.332; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.332; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica3 state=active
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.335; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.337; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.340; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.342; 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=2812
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.752; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.753; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:60675/v_lz collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.756; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica4
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.757; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica4 address:http://127.0.0.1:44705/v_lz collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.757; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:60675/v_lz/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.758; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:60675/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.758; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica2
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.759; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.760; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:44705/v_lz/awholynewcollection_0_shard1_replica4/ and leader is http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.760; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica4 baseURL=http://127.0.0.1:44705/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.761; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica4
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.761; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.760; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.760; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.762; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.762; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.762; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard1_replica4 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.760; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.764; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.764; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.764; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica2 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.763; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.765; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica4 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.764; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica5 address:http://127.0.0.1:56844/v_lz collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.768; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.769; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=1&shard=shard1&name=awholynewcollection_0_shard1_replica4&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3238
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.771; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.772; 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=3242
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.772; org.apache.solr.core.CoreContainer; registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.773; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.773; org.apache.solr.cloud.ZkController; Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:47859/v_lz collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.774; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.776; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:56844/v_lz/awholynewcollection_0_shard1_replica5/ and leader is http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.777; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica5 baseURL=http://127.0.0.1:56844/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.777; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica5
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.777; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:47859/v_lz/awholynewcollection_0_shard1_replica1/ and leader is http://127.0.0.1:34584/v_lz/awholynewcollection_0_shard1_replica3/
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.778; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:60675_v_lz_awholynewcollection_0_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.777; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.778; org.apache.solr.cloud.ZkController; No LogReplay needed for core=awholynewcollection_0_shard1_replica1 baseURL=http://127.0.0.1:47859/v_lz
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.779; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.779; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:44705_v_lz_awholynewcollection_0_shard1_replica4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.780; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.779; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard1_replica5 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.779; org.apache.solr.cloud.ZkController; Core needs to recover:awholynewcollection_0_shard1_replica1
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.781; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.781; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.782; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica5 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.782; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.783; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.783; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.783; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.784; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={numShards=1&shard=shard1&name=awholynewcollection_0_shard1_replica5&action=CREATE&collection=awholynewcollection_0&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=3252
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.786; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.787; 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=3258
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.787; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=awholynewcollection_0_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.787; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:56844_v_lz_awholynewcollection_0_shard1_replica5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.787; org.apache.solr.cloud.OverseerCollectionProcessor; Finished create command on all shards for collection: awholynewcollection_0
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.788; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.789; org.apache.solr.cloud.ZkController; publishing core=awholynewcollection_0_shard1_replica1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.790; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.794; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:47859_v_lz_awholynewcollection_0_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.823; 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-04-23 04:01:59.825; org.apache.solr.cloud.DistributedQueue$LatchChildWatcher; Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.825; org.apache.solr.cloud.OverseerCollectionProcessor; Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000002 complete, response:{success={null={responseHeader={status=0,QTime=2812},core=awholynewcollection_0_shard1_replica3,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1366689709844/solr.xml},null={responseHeader={status=0,QTime=3238},core=awholynewcollection_0_shard1_replica4,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1366689708626/solr.xml},null={responseHeader={status=0,QTime=3242},core=awholynewcollection_0_shard1_replica2,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1366689711026/solr.xml},null={responseHeader={status=0,QTime=3252},core=awholynewcollection_0_shard1_replica5,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1366689708409/solr.xml},null={responseHeader={status=0,QTime=3258},core=awholynewcollection_0_shard1_replica1,saved=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/solr.xml}}}
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.826; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/collections params={numShards=1&maxShardsPerNode=2&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2} status=0 QTime=3304
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.828; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.829; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-23 04:01:59.830; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1793f50 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null ty

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

> INFO  - 2013-04-23 04:06:33.911; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.911; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.911; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.913; org.apache.solr.core.SolrCore; [awholynewcollection_5_shard1_replica2] Closing main searcher on request.
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.914; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.914; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data/index;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.914; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data/index
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.915; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data;done=false>>]
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.915; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1366689712197/awholynewcollection_5_shard1_replica2/data
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.916; org.apache.solr.cloud.Overseer$ClusterStateUpdater; According to ZK I (id=89567376613834764-127.0.0.1:47859_v_lz-n_0000000004) am no longer a leader.
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.940; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/v_lz,null}
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.995; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:33.998; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:38540 38540
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-CollectionsAPIDistributedZkTest-1366689706628
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=8ACBD6D7FB3B561A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sr_CS -Dtests.timezone=Etc/GMT-13 -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE  287s J1 | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
[junit4:junit4]    > at __randomizedtesting.SeedInfo.seed([8ACBD6D7FB3B561A:B2D58CF8C643626]: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:509)
[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-04-23 04:06:34.055; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> 287434 T1669 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4]   1> WARN  - 2013-04-23 04:06:35.219; org.apache.solr.cloud.LeaderElector$1;
[junit4:junit4]   1> org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/awholynewcollection_5/leader_elect/shard1/election
[junit4:junit4]   1> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4]   1> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4]   1> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4]   1> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4]   1> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4]   1> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4]   1> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4]   1> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4]   1> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4]   1> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4]   1> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4]   1> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4]   1> INFO  - 2013-04-23 04:06:35.221; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   1> WARN  - 2013-04-23 04:06:35.221; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> WARN  - 2013-04-23 04:06:35.221; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=sr_CS, timezone=Etc/GMT-13
[junit4:junit4]   2> NOTE: Linux 3.2.0-40-generic i386/Oracle Corporation 1.7.0_21 (32-bit)/cpus=8,threads=3,free=48463584,total=143142912
[junit4:junit4]   2> NOTE: All tests run in this JVM: [BadCopyFieldTest, TestComponentsName, TestCSVLoader, TestElisionMultitermQuery, TestRandomFaceting, TestZkChroot, NumericFieldsTest, EchoParamsTest, DebugComponentTest, BasicDistributedZk2Test, FileUtilsTest, TestRangeQuery, IndexReaderFactoryTest, TestDistributedGrouping, OpenExchangeRatesOrgProviderTest, HighlighterConfigTest, TestFieldResource, TestJmxMonitoredMap, SortByFunctionTest, TestDistributedSearch, TestAnalyzedSuggestions, IndexBasedSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestFastOutputStream, TestQueryTypes, UniqFieldsUpdateProcessorFactoryTest, TestSystemIdResolver, TestWordDelimiterFilterFactory, NotRequiredUniqueKeyTest, DocumentAnalysisRequestHandlerTest, HardAutoCommitTest, StatsComponentTest, TimeZoneUtilsTest, DocValuesMultiTest, TestLuceneMatchVersion, TestSuggestSpellingConverter, SolrRequestParserTest, TestDFRSimilarityFactory, TestDynamicFieldResource, StandardRequestHandlerTest, TestSolrQueryParserResource, SuggesterTSTTest, CurrencyFieldXmlFileTest, TestCodecSupport, TestCoreDiscovery, SignatureUpdateProcessorFactoryTest, TestMergePolicyConfig, TestBinaryField, ChaosMonkeySafeLeaderTest, SampleTest, DirectUpdateHandlerTest, SolrIndexConfigTest, ShardSplitTest, TestFieldCollectionResource, TestFieldTypeCollectionResource, DateMathParserTest, TestQuerySenderNoQuery, TestDefaultSimilarityFactory, TestBM25SimilarityFactory, CollectionsAPIDistributedZkTest]
[junit4:junit4] Completed on J1 in 288.71s, 1 test, 1 failure <<< FAILURES!

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

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




---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]