You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/04/09 08:14:22 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b84) - Build #
5083 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5083/
Java: 32bit/jdk1.8.0-ea-b84 -client -XX:+UseG1GC
2 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:54420/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
Stack Trace:
org.apache.solr.common.SolrException: Server at http://127.0.0.1:54420/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([21156EF93029B37A:A0F3E0E14776D346]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
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:487)
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)
REGRESSION: org.apache.solr.cloud.UnloadDistributedZkTest.testDistribSearch
Error Message:
Still found shard2 in collection test_unload_shard_and_collection
Stack Trace:
java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
at __randomizedtesting.SeedInfo.seed([21156EF93029B37A:A0F3E0E14776D346]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:127)
at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
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:487)
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 9234 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.UnloadDistributedZkTest
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.669; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.673; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.674; 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-09 06:02:30.674; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.774; org.apache.solr.cloud.ZkTestServer; start zk server on port:52898
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.776; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.783; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@4f45b8 name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.783; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.784; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.788; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.789; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@88b501 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.790; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.790; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.793; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.796; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.798; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.800; 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-09 06:02:30.801; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.805; 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-09 06:02:30.806; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.809; 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-09 06:02:30.810; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.813; 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-09 06:02:30.814; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.817; 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-09 06:02:30.818; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.821; 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-09 06:02:30.821; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.823; 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-09 06:02:30.824; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.827; 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-09 06:02:30.827; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.830; 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-09 06:02:30.831; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.904; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.916; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:57239
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.917; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.918; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.918; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1365487350834
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.919; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1365487350834/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.919; org.apache.solr.core.CoreContainer; New CoreContainer 5713584
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.920; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1365487350834/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.920; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-controljetty-1365487350834/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.941; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.942; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.942; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.943; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.943; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.944; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.944; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.944; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.945; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.945; 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-09 06:02:30.952; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.964; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:52898/solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.965; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.966; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.967; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1085deb name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.967; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.969; 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-09 06:02:30.973; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.974; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@105f345 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.974; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.976; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.978; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.980; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.982; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57239_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.983; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:57239_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.985; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.990; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.992; org.apache.solr.cloud.Overseer; Overseer (id=89488579013902339-127.0.0.1:57239_-n_0000000000) starting
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.994; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.997; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4] 1> INFO - 2013-04-09 06:02:30.997; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.000; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.001; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.003; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.004; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.005; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.005; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.008; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.009; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.010; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1284379 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.010; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.012; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.013; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.072; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.074; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:44526
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.075; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.075; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.076; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.076; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.076; org.apache.solr.core.CoreContainer; New CoreContainer 12644219
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.077; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.077; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.098; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.098; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.099; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.099; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.099; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.100; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.100; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.101; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.101; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.101; 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-09 06:02:31.130; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.142; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:52898/solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.143; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.143; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.145; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@49421b name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.145; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.147; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.150; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.151; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@13bb21a name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.152; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:31.155; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.158; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44526_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.164; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:44526_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.175; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.175; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.175; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.180; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.181; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.181; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.245; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.247; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:43083
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.248; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.248; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.249; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.249; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.249; org.apache.solr.core.CoreContainer; New CoreContainer 30180568
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.250; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.250; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.279; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.279; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.280; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.280; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.280; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.281; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.281; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.282; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.282; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.282; 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-09 06:02:32.289; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.301; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:52898/solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.302; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.303; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.304; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@10635a0 name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.304; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.306; 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-09 06:02:32.309; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.310; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@195164a name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.310; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:32.315; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.319; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43083_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.321; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:43083_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.324; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.324; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.324; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.324; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.329; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.329; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.330; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.391; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.393; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:35521
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.394; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.394; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.395; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.395; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.396; org.apache.solr.core.CoreContainer; New CoreContainer 1357163
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.396; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.396; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.432; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.432; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.433; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.433; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.434; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.434; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.435; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.435; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.436; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.436; 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-09 06:02:33.444; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.456; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:52898/solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.457; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.458; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.459; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@7a09eb name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.460; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.463; 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-09 06:02:33.466; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.467; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1149d27 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.467; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:33.473; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.476; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35521_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.478; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:35521_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.481; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.481; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.482; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.482; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.481; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.486; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.487; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.487; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.550; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.552; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:43775
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.553; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.554; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.554; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1365487354489
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.554; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1365487354489/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.555; org.apache.solr.core.CoreContainer; New CoreContainer 24688197
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.555; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1365487354489/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.556; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty4-1365487354489/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.576; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.577; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.577; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.577; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.578; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.578; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.579; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.579; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.579; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.580; 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-09 06:02:34.586; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.611; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:52898/solr
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.612; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.612; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.614; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1e11afc name:ZooKeeperConnection Watcher:127.0.0.1:52898 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.614; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.617; 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-09 06:02:34.620; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.621; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1dc1d4 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.621; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:34.625; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.627; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43775_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.630; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:43775_
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.632; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.633; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.633; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.633; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.633; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.633; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.637; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.637; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.638; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.640; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.644; org.apache.solr.core.CoreContainer; Creating SolrCore 'unloadcollection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/unloadcollection1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.645; org.apache.solr.cloud.ZkController; Check for collection zkNode:unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.646; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.646; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.648; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.649; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.651; org.apache.solr.cloud.ZkController; Load collection config from:/collections/unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.652; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/unloadcollection1/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.680; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.729; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.731; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:35.735; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.208; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.214; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.217; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.246; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.250; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.253; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:36.255; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:36.255; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.255; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:36.257; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:36.257; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.258; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.258; org.apache.solr.core.SolrCore; [unloadcollection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/unloadcollection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.258; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a623c5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.259; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.260; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.260; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n/index/
[junit4:junit4] 1> WARN - 2013-04-09 06:02:36.260; org.apache.solr.core.SolrCore; [unloadcollection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n/index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.261; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n/index
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.262; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.263; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.264; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.265; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.265; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.266; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.266; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.267; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.267; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.268; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.268; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.270; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.273; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@21e9bc main
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.274; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n/tlog
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.274; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.275; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.278; org.apache.solr.core.SolrCore; [unloadcollection1] Registered new searcher Searcher@21e9bc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:36.279; org.apache.solr.cloud.ZkController; publishing core=unloadcollection1 state=down
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.011; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.012; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44526_",
[junit4:junit4] 1> "core":"unloadcollection1",
[junit4:junit4] 1> "state":"down",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44526",
[junit4:junit4] 1> "shard":null,
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.012; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection unloadcollection with numShards 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.012; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.056; 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-09 06:02:37.056; 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-09 06:02:37.056; 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-09 06:02:37.056; 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-09 06:02:37.056; 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-09 06:02:37.056; 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-09 06:02:37.282; org.apache.solr.core.CoreContainer; registering core: unloadcollection1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.283; org.apache.solr.cloud.ZkController; Register replica - core:unloadcollection1 address:http://127.0.0.1:44526 collection:unloadcollection shard:shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.284; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/unloadcollection/leader_elect/shard1/election
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.293; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.296; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.296; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.296; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:44526/unloadcollection1/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.297; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.297; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:44526/unloadcollection1/ has no replicas
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.297; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:44526/unloadcollection1/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:37.298; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/unloadcollection/leaders/shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.560; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.568; 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-09 06:02:38.568; 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-09 06:02:38.568; 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-09 06:02:38.568; 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-09 06:02:38.568; 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-09 06:02:38.568; 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-09 06:02:38.572; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:44526/unloadcollection1/ and leader is http://127.0.0.1:44526/unloadcollection1/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.573; org.apache.solr.cloud.ZkController; No LogReplay needed for core=unloadcollection1 baseURL=http://127.0.0.1:44526
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.573; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.573; org.apache.solr.cloud.ZkController; publishing core=unloadcollection1 state=active
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.583; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.584; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.590; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty1-1365487351014/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.592; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={version=2&wt=javabin&name=unloadcollection1&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487355643unloadcollection1_1n&numShards=1&collection=unloadcollection&action=CREATE} status=0 QTime=2948
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.592; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.594; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.596; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@997192 name:ZooKeeperConnection Watcher:127.0.0.1:52898/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.597; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.598; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.601; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.602; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.605; org.apache.solr.core.CoreContainer; Creating SolrCore 'unloadcollection2' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.606; org.apache.solr.cloud.ZkController; Check for collection zkNode:unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.607; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.607; org.apache.solr.cloud.ZkController; Load collection config from:/collections/unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.608; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/unloadcollection2/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.641; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.691; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.693; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:38.697; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.172; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.178; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.181; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.192; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.199; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.207; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:39.208; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:39.209; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.210; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:39.211; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:39.211; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.212; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.212; org.apache.solr.core.SolrCore; [unloadcollection2] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/unloadcollection2/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.213; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a623c5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.213; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.214; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.215; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index/
[junit4:junit4] 1> WARN - 2013-04-09 06:02:39.215; org.apache.solr.core.SolrCore; [unloadcollection2] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.216; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.218; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@166c413 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8b456; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.219; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.221; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.221; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.222; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.223; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.223; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.224; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.224; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.225; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.225; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.227; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.230; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@125cddc main
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.231; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/tlog
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.231; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.231; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.235; org.apache.solr.core.SolrCore; [unloadcollection2] Registered new searcher Searcher@125cddc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.236; org.apache.solr.cloud.ZkController; publishing core=unloadcollection2 state=down
[junit4:junit4] 1> INFO - 2013-04-09 06:02:39.236; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.073; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.074; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4] 1> "core_node_name":"127.0.0.1:44526__unloadcollection1",
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"1",
[junit4:junit4] 1> "node_name":"127.0.0.1:44526_",
[junit4:junit4] 1> "core":"unloadcollection1",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:44526",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.077; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:43083_",
[junit4:junit4] 1> "core":"unloadcollection2",
[junit4:junit4] 1> "state":"down",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:43083",
[junit4:junit4] 1> "shard":null,
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.077; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.078; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.082; 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-09 06:02:40.082; 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-09 06:02:40.083; 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-09 06:02:40.083; 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-09 06:02:40.082; 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-09 06:02:40.082; 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-09 06:02:40.082; 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-09 06:02:40.238; org.apache.solr.core.CoreContainer; registering core: unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.239; org.apache.solr.cloud.ZkController; Register replica - core:unloadcollection2 address:http://127.0.0.1:43083 collection:unloadcollection shard:shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.243; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:43083/unloadcollection2/ and leader is http://127.0.0.1:44526/unloadcollection1/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.243; org.apache.solr.cloud.ZkController; No LogReplay needed for core=unloadcollection2 baseURL=http://127.0.0.1:43083
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.244; org.apache.solr.cloud.ZkController; Core needs to recover:unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.244; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.245; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=unloadcollection2 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.245; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.245; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.246; org.apache.solr.cloud.ZkController; publishing core=unloadcollection2 state=recovering
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.246; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.247; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.247; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.251; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:43083__unloadcollection2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.253; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty2-1365487352186/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.254; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={version=2&wt=javabin&name=unloadcollection2&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n&collection=unloadcollection&action=CREATE} status=0 QTime=1649
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.255; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.257; org.apache.solr.cloud.AbstractDistribZkTestBase; Wait for recoveries to finish - collection: unloadcollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 1> INFO - 2013-04-09 06:02:40.259; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:41.261; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:41.591; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:41.592; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":"127.0.0.1:43083__unloadcollection2",
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:43083_",
[junit4:junit4] 1> "core":"unloadcollection2",
[junit4:junit4] 1> "state":"recovering",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:43083",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:41.652; 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-09 06:02:42.252; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:43083__unloadcollection2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:42.253; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={version=2&checkLive=true&wt=javabin&onlyIfLeader=true&state=recovering&core=unloadcollection1&coreNodeName=127.0.0.1:43083__unloadcollection2&nodeName=127.0.0.1:43083_&action=PREPRECOVERY} status=0 QTime=2002
[junit4:junit4] 1> INFO - 2013-04-09 06:02:42.263; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:43.266; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.254; org.apache.solr.cloud.RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:44526/unloadcollection1/ core=unloadcollection2 - recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.254; org.apache.solr.update.PeerSync; PeerSync: core=unloadcollection2 url=http://127.0.0.1:43083 START replicas=[http://127.0.0.1:44526/unloadcollection1/] nUpdates=100
[junit4:junit4] 1> WARN - 2013-04-09 06:02:44.255; org.apache.solr.update.PeerSync; no frame of reference to tell of we've missed updates
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.255; org.apache.solr.cloud.RecoveryStrategy; PeerSync Recovery was not successful - trying replication. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.255; org.apache.solr.cloud.RecoveryStrategy; Starting Replication Recovery. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.256; org.apache.solr.cloud.RecoveryStrategy; Begin buffering updates. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.256; org.apache.solr.update.UpdateLog; Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.256; org.apache.solr.cloud.RecoveryStrategy; Attempting to replicate from http://127.0.0.1:44526/unloadcollection1/. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.256; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.260; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/get params={version=2&wt=javabin&distrib=false&qt=/get&getVersions=100} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.260; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.263; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.263; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.264; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.264; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.265; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@26c7f5 realtime
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.265; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.265; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&commit=true&wt=javabin&commit_end_point=true&waitSearcher=true&openSearcher=false&softCommit=false} {commit=} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.266; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for 10000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.267; org.apache.solr.handler.SnapPuller; No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.268; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.270; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for 10000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.270; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.271; org.apache.solr.handler.SnapPuller; Master's generation: 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.271; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.271; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.273; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={version=2&wt=javabin&command=filelist&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.274; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.275; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index.20130409020244274
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.276; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b7ac94 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f1651) fullCopy=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.290; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={checksum=true&file=segments_2&wt=filestream&command=filecontent&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.293; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.295; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.295; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.296; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@166c413 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8b456; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@166c413 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c8b456; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.297; org.apache.solr.core.SolrDeletionPolicy; newest commit = 2[segments_2]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.297; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.297; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@993b7b main
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.298; org.apache.solr.core.SolrCore; [unloadcollection2] Registered new searcher Searcher@993b7b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.299; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index.20130409020244274 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index.20130409020244274;done=true>>]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.299; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index.20130409020244274
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.299; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487358604unloadcollection1_2n/index.20130409020244274
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.300; org.apache.solr.cloud.RecoveryStrategy; No replay needed. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.300; org.apache.solr.cloud.RecoveryStrategy; Replication Recovery was successful - registering as Active. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.300; org.apache.solr.cloud.ZkController; publishing core=unloadcollection2 state=active
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.300; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.301; org.apache.solr.cloud.RecoveryStrategy; Finished recovery process. core=unloadcollection2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.661; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.662; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":"127.0.0.1:43083__unloadcollection2",
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:43083_",
[junit4:junit4] 1> "core":"unloadcollection2",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:43083",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:44.665; 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-09 06:02:45.270; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.271; org.apache.solr.cloud.AbstractDistribZkTestBase; Recoveries finished - collection: unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.272; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.275; org.apache.solr.core.CoreContainer; Creating SolrCore 'unloadcollection3' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.275; org.apache.solr.cloud.ZkController; Check for collection zkNode:unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.276; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.277; org.apache.solr.cloud.ZkController; Load collection config from:/collections/unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.278; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/unloadcollection3/'
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.308; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.345; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.347; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.351; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.866; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.873; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.887; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.901; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.904; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.908; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:45.909; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:45.909; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.910; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 1> WARN - 2013-04-09 06:02:45.911; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4] 1> WARN - 2013-04-09 06:02:45.911; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.912; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.912; org.apache.solr.core.SolrCore; [unloadcollection3] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/unloadcollection3/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.912; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a623c5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.913; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.914; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.914; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index/
[junit4:junit4] 1> WARN - 2013-04-09 06:02:45.914; org.apache.solr.core.SolrCore; [unloadcollection3] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index' doesn't exist. Creating new index...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.915; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.916; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4f3e63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1648537; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.916; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.918; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.918; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.919; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.919; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.920; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.920; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.921; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.921; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.922; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.924; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.927; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@1ed3149 main
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.927; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/tlog
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.928; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.928; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.932; org.apache.solr.core.SolrCore; [unloadcollection3] Registered new searcher Searcher@1ed3149 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.932; org.apache.solr.cloud.ZkController; publishing core=unloadcollection3 state=down
[junit4:junit4] 1> INFO - 2013-04-09 06:02:45.933; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.169; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.170; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":null,
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:35521_",
[junit4:junit4] 1> "core":"unloadcollection3",
[junit4:junit4] 1> "state":"down",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:35521",
[junit4:junit4] 1> "shard":null,
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.170; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.170; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard=shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.175; 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-09 06:02:46.934; org.apache.solr.core.CoreContainer; registering core: unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.935; org.apache.solr.cloud.ZkController; Register replica - core:unloadcollection3 address:http://127.0.0.1:35521 collection:unloadcollection shard:shard1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.938; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:35521/unloadcollection3/ and leader is http://127.0.0.1:44526/unloadcollection1/
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.939; org.apache.solr.cloud.ZkController; No LogReplay needed for core=unloadcollection3 baseURL=http://127.0.0.1:35521
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.940; org.apache.solr.cloud.ZkController; Core needs to recover:unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.941; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.942; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process. core=unloadcollection3 recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.943; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.943; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.944; org.apache.solr.cloud.ZkController; publishing core=unloadcollection3 state=recovering
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.945; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.946; org.apache.solr.core.CoreContainer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.947; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.953; org.apache.solr.handler.admin.CoreAdminHandler; Going to wait for coreNodeName: 127.0.0.1:35521__unloadcollection3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.959; org.apache.solr.core.SolrXMLSerializer; Persisting cores config to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.UnloadDistributedZkTest-jetty3-1365487353332/solr.xml
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.960; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={version=2&wt=javabin&name=unloadcollection3&dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n&collection=unloadcollection&action=CREATE} status=0 QTime=1685
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.961; org.apache.solr.cloud.AbstractDistribZkTestBase; Wait for recoveries to finish - collection: unloadcollection failOnTimeout:true timeout (sec):230
[junit4:junit4] 1> INFO - 2013-04-09 06:02:46.963; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:47.680; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:47.681; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":"127.0.0.1:35521__unloadcollection3",
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:35521_",
[junit4:junit4] 1> "core":"unloadcollection3",
[junit4:junit4] 1> "state":"recovering",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:35521",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.685; 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-09 06:02:47.954; org.apache.solr.handler.admin.CoreAdminHandler; Waited coreNodeName: 127.0.0.1:35521__unloadcollection3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:47.955; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={version=2&checkLive=true&wt=javabin&onlyIfLeader=true&state=recovering&core=unloadcollection1&coreNodeName=127.0.0.1:35521__unloadcollection3&nodeName=127.0.0.1:35521_&action=PREPRECOVERY} status=0 QTime=1002
[junit4:junit4] 1> INFO - 2013-04-09 06:02:47.965; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:48.968; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.956; org.apache.solr.cloud.RecoveryStrategy; Attempting to PeerSync from http://127.0.0.1:44526/unloadcollection1/ core=unloadcollection3 - recoveringAfterStartup=true
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.957; org.apache.solr.update.PeerSync; PeerSync: core=unloadcollection3 url=http://127.0.0.1:35521 START replicas=[http://127.0.0.1:44526/unloadcollection1/] nUpdates=100
[junit4:junit4] 1> WARN - 2013-04-09 06:02:49.958; org.apache.solr.update.PeerSync; no frame of reference to tell of we've missed updates
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.958; org.apache.solr.cloud.RecoveryStrategy; PeerSync Recovery was not successful - trying replication. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.958; org.apache.solr.cloud.RecoveryStrategy; Starting Replication Recovery. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.959; org.apache.solr.cloud.RecoveryStrategy; Begin buffering updates. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.959; org.apache.solr.update.UpdateLog; Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.960; org.apache.solr.cloud.RecoveryStrategy; Attempting to replicate from http://127.0.0.1:44526/unloadcollection1/. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.960; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.960; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/get params={version=2&wt=javabin&distrib=false&qt=/get&getVersions=100} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.968; org.apache.solr.update.DirectUpdateHandler2; start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.970; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@1917222 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1fffd67; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.971; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.971; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.972; org.apache.solr.update.DirectUpdateHandler2; end_commit_flush
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.973; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&commit=true&wt=javabin&commit_end_point=true&waitSearcher=true&openSearcher=false&softCommit=false} {commit=} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.974; org.apache.solr.handler.ReplicationHandler; Commits will be reserved for 10000
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.975; org.apache.solr.handler.SnapPuller; No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.977; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={version=2&wt=javabin&command=indexversion&qt=/replication} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.978; org.apache.solr.handler.SnapPuller; Master's generation: 3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.978; org.apache.solr.handler.SnapPuller; Slave's generation: 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.978; org.apache.solr.handler.SnapPuller; Starting replication process
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.980; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={version=2&wt=javabin&command=filelist&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.981; org.apache.solr.handler.SnapPuller; Number of files in latest index in master: 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.983; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index.20130409020249982
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.983; org.apache.solr.handler.SnapPuller; Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1e01d10 lockFactory=org.apache.lucene.store.NativeFSLockFactory@19f1199) fullCopy=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:49.997; org.apache.solr.core.SolrCore; [unloadcollection1] webapp= path=/replication params={checksum=true&file=segments_3&wt=filestream&command=filecontent&qt=/replication&generation=3} status=0 QTime=0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.000; org.apache.solr.handler.SnapPuller; Total time taken for download : 0 secs
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.002; org.apache.solr.update.DefaultSolrCoreState; Creating new IndexWriter...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.002; org.apache.solr.update.DefaultSolrCoreState; Waiting until IndexWriter is unused... core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.004; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onInit: commits:num=2
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4f3e63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1648537; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 1> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4f3e63 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1648537; maxCacheMB=0.0634765625 maxMergeSizeMB=0.5400390625)),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.005; org.apache.solr.core.SolrDeletionPolicy; newest commit = 3[segments_3]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.005; org.apache.solr.update.DefaultSolrCoreState; New IndexWriter is ready to be used.
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.006; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@14cffca main
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.008; org.apache.solr.core.SolrCore; [unloadcollection3] Registered new searcher Searcher@14cffca main{StandardDirectoryReader(segments_3:1:nrt)}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.009; org.apache.solr.core.CachingDirectoryFactory; looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index.20130409020249982 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index.20130409020249982;done=true>>]
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.009; org.apache.solr.core.CachingDirectoryFactory; Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index.20130409020249982
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.009; org.apache.solr.core.CachingDirectoryFactory; Removing directory before core close: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-UnloadDistributedZkTest-1365487350674/1365487365274unloadcollection_3n/index.20130409020249982
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.010; org.apache.solr.cloud.RecoveryStrategy; No replay needed. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.010; org.apache.solr.cloud.RecoveryStrategy; Replication Recovery was successful - registering as Active. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.010; org.apache.solr.cloud.ZkController; publishing core=unloadcollection3 state=active
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.010; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.012; org.apache.solr.cloud.RecoveryStrategy; Finished recovery process. core=unloadcollection3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.694; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.695; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4] 1> "core_node_name":"127.0.0.1:35521__unloadcollection3",
[junit4:junit4] 1> "operation":"state",
[junit4:junit4] 1> "numShards":"2",
[junit4:junit4] 1> "node_name":"127.0.0.1:35521_",
[junit4:junit4] 1> "core":"unloadcollection3",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "shard_state":"active",
[junit4:junit4] 1> "shard_range":null,
[junit4:junit4] 1> "roles":null,
[junit4:junit4] 1> "base_url":"http://127.0.0.1:35521",
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "collection":"unloadcollection"}
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.708; 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-09 06:02:50.709; 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-09 06:02:50.709; 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-09 06:02:50.709; 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-09 06:02:50.708; 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-09 06:02:50.708; 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-09 06:02:50.709; 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-09 06:02:50.974; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper...
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.976; org.apache.solr.cloud.AbstractDistribZkTestBase; Recoveries finished - collection: unloadcollection
[junit4:junit4] 1> INFO - 2013-04-09 06:02:50.976; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.000; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[20 (1431817285527404544)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.004; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[20 (1431817285527404544)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.005; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[20 (1431817285527404544)]} 0 11
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.005; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[20]} 0 14
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.016; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[21 (1431817285544181760)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.017; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[21 (1431817285544181760)]} 0 3
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.018; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[21 (1431817285544181760)]} 0 8
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.019; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[21]} 0 11
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.029; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[22 (1431817285558861824)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.029; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[22 (1431817285558861824)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.031; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[22 (1431817285558861824)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.032; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[22]} 0 11
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.042; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[23 (1431817285573541888)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.043; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[23 (1431817285573541888)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.044; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[23 (1431817285573541888)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.046; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[23]} 0 11
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.056; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[24 (1431817285587173376)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.056; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[24 (1431817285587173376)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.057; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[24 (1431817285587173376)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.059; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[24]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.068; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[25 (1431817285600804864)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.068; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[25 (1431817285600804864)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.070; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[25 (1431817285600804864)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.071; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[25]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.080; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[26 (1431817285613387776)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.081; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[26 (1431817285613387776)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.082; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[26 (1431817285613387776)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.083; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[26]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.093; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[27 (1431817285627019264)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.093; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[27 (1431817285627019264)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.095; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[27 (1431817285627019264)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.097; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[27]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.107; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[28 (1431817285640650752)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.107; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[28 (1431817285640650752)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.109; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[28 (1431817285640650752)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.110; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[28]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.119; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[29 (1431817285655330816)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.119; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[29 (1431817285655330816)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.121; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[29 (1431817285655330816)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.123; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[29]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.131; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[30 (1431817285667913728)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.131; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[30 (1431817285667913728)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.132; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[30 (1431817285667913728)]} 0 4
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.132; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[30]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.139; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[31 (1431817285676302336)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.139; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[31 (1431817285676302336)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.140; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[31 (1431817285676302336)]} 0 4
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.141; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[31]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.148; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[32 (1431817285685739520)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.148; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[32 (1431817285685739520)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.149; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[32 (1431817285685739520)]} 0 4
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.149; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[32]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.156; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[33 (1431817285694128128)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.156; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[33 (1431817285694128128)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.157; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[33 (1431817285694128128)]} 0 4
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.158; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[33]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.164; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[34 (1431817285703565312)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.164; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[34 (1431817285703565312)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.166; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[34 (1431817285703565312)]} 0 4
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.166; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[34]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.174; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[35 (1431817285713002496)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.174; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[35 (1431817285713002496)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.176; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[35 (1431817285713002496)]} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.177; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[35]} 0 8
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.185; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[36 (1431817285724536832)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.185; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[36 (1431817285724536832)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.186; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[36 (1431817285724536832)]} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.187; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[36]} 0 8
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.195; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[37 (1431817285733974016)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.195; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[37 (1431817285733974016)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.197; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[37 (1431817285733974016)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.198; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[37]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.207; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[38 (1431817285746556928)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.208; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[38 (1431817285746556928)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.209; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[38 (1431817285746556928)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.210; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[38]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.220; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[39 (1431817285760188416)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.222; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[39 (1431817285760188416)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.223; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[39 (1431817285760188416)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.224; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[39]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.234; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[40 (1431817285774868480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.234; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[40 (1431817285774868480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.236; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[40 (1431817285774868480)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.237; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[40]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.247; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[41 (1431817285788499968)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.247; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[41 (1431817285788499968)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.249; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[41 (1431817285788499968)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.250; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[41]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.259; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[42 (1431817285801082880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.259; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[42 (1431817285801082880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.261; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[42 (1431817285801082880)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.262; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[42]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.272; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[43 (1431817285814714368)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.273; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[43 (1431817285814714368)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.274; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[43 (1431817285814714368)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.276; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[43]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.285; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[44 (1431817285828345856)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.285; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[44 (1431817285828345856)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.286; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[44 (1431817285828345856)]} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.288; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[44]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.297; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[45 (1431817285840928768)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.297; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[45 (1431817285840928768)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.299; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[45 (1431817285840928768)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.300; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[45]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.309; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[46 (1431817285853511680)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.309; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[46 (1431817285853511680)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.311; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[46 (1431817285853511680)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.312; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[46]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.321; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[47 (1431817285867143168)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.322; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[47 (1431817285867143168)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.323; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[47 (1431817285867143168)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.325; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[47]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.334; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[48 (1431817285879726080)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.334; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[48 (1431817285879726080)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.336; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[48 (1431817285879726080)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.337; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[48]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.346; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[49 (1431817285892308992)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.347; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[49 (1431817285892308992)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.348; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[49 (1431817285892308992)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.350; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[49]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.359; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[50 (1431817285905940480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.359; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[50 (1431817285905940480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.361; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[50 (1431817285905940480)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.362; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[50]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.372; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[51 (1431817285918523392)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.372; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[51 (1431817285918523392)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.374; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[51 (1431817285918523392)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.374; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[51]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.384; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[52 (1431817285932154880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.384; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[52 (1431817285932154880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.386; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[52 (1431817285932154880)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.388; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[52]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.397; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[53 (1431817285945786368)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.397; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[53 (1431817285945786368)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.399; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[53 (1431817285945786368)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.400; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[53]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.410; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[54 (1431817285958369280)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.410; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[54 (1431817285958369280)]} 0 2
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.412; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[54 (1431817285958369280)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.413; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[54]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.422; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[55 (1431817285972000768)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.422; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[55 (1431817285972000768)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.425; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[55 (1431817285972000768)]} 0 7
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.426; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[55]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.435; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[56 (1431817285985632256)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.435; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[56 (1431817285985632256)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.437; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[56 (1431817285985632256)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.438; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[56]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.447; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[57 (1431817285998215168)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.447; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[57 (1431817285998215168)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.449; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[57 (1431817285998215168)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.450; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[57]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.460; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[58 (1431817286011846656)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.460; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[58 (1431817286011846656)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.462; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[58 (1431817286011846656)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.463; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[58]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.472; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[59 (1431817286024429568)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.472; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[59 (1431817286024429568)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.474; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[59 (1431817286024429568)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.475; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[59]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.484; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[60 (1431817286037012480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.484; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[60 (1431817286037012480)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.486; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[60 (1431817286037012480)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.488; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[60]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.497; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[61 (1431817286050643968)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.497; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[61 (1431817286050643968)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.498; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[61 (1431817286050643968)]} 0 5
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.500; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[61]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.509; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[62 (1431817286063226880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.509; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[62 (1431817286063226880)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.511; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[62 (1431817286063226880)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.512; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[62]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.521; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[63 (1431817286075809792)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.521; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[63 (1431817286075809792)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.523; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[63 (1431817286075809792)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.524; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[63]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.533; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[64 (1431817286089441280)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.533; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[64 (1431817286089441280)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.535; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[64 (1431817286089441280)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.536; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[64]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.545; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[65 (1431817286100975616)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.545; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[65 (1431817286100975616)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.547; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[65 (1431817286100975616)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.548; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[65]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.558; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[66 (1431817286114607104)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.558; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[66 (1431817286114607104)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.559; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[66 (1431817286114607104)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.561; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[66]} 0 10
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.570; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[67 (1431817286127190016)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.570; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[67 (1431817286127190016)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.572; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[67 (1431817286127190016)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.573; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[67]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.582; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[68 (1431817286139772928)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.582; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[68 (1431817286139772928)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.584; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[68 (1431817286139772928)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.585; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[68]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.594; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[69 (1431817286152355840)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.594; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[69 (1431817286152355840)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.596; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[69 (1431817286152355840)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.597; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[69]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.606; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[70 (1431817286165987328)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.606; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[70 (1431817286165987328)]} 0 0
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.608; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[70 (1431817286165987328)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.610; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[70]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.619; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[71 (1431817286178570240)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.619; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[71 (1431817286178570240)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.621; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[71 (1431817286178570240)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.622; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[71]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.631; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[72 (1431817286192201728)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.632; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[72 (1431817286192201728)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.633; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[72 (1431817286192201728)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.634; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[72]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.644; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[73 (1431817286204784640)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.644; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection2] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:44526/unloadcollection1/&update.distrib=FROMLEADER} {add=[73 (1431817286204784640)]} 0 1
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.646; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection1] webapp= path=/update params={version=2&wt=javabin&distrib.from=http://127.0.0.1:35521/unloadcollection3/&update.distrib=TOLEADER} {add=[73 (1431817286204784640)]} 0 6
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.647; org.apache.solr.update.processor.LogUpdateProcessor; [unloadcollection3] webapp= path=/update params={version=2&wt=javabin} {add=[73]} 0 9
[junit4:junit4] 1> INFO - 2013-04-09 06:02:51.656; org.apache.solr.update.processor.LogUpdate
[...truncated too long message...]
4] 1> "base_url":"http://127.0.0.1:54759",
[junit4:junit4] 1> "shard":"shard2",
[junit4:junit4] 1> "collection":"collection1"}
[junit4:junit4] 1> INFO - 2013-04-09 06:07:44.554; 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: 1)
[junit4:junit4] 1> INFO - 2013-04-09 06:07:44.558; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 1> INFO - 2013-04-09 06:07:44.610; org.apache.solr.cloud.ChaosMonkey; monkey: stop shard! 42571
[junit4:junit4] 1> INFO - 2013-04-09 06:07:44.611; org.apache.solr.core.CoreContainer; Shutting down CoreContainer instance=30941732
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.612; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.613; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.618; org.apache.solr.core.SolrCore; [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1e3d1c1
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.629; org.apache.solr.update.DirectUpdateHandler2; closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.631; org.apache.solr.update.SolrCoreState; Closing SolrCoreState
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.631; org.apache.solr.update.DefaultSolrCoreState; SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.631; org.apache.solr.update.DefaultSolrCoreState; closing IndexWriter with IndexWriterCloser
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.633; org.apache.solr.core.SolrCore; [collection1] Closing main searcher on request.
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.634; org.apache.solr.core.CachingDirectoryFactory; Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.634; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4;done=false>>]
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.634; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.635; org.apache.solr.core.CachingDirectoryFactory; looking to close ./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4/index;done=false>>]
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.635; org.apache.solr.core.CachingDirectoryFactory; Closing directory: ./org.apache.solr.cloud.BasicDistributedZk2Test-1365487632722/jetty4/index
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.636; org.apache.solr.cloud.Overseer$ClusterStateUpdater; According to ZK I (id=89488597498331148-127.0.0.1:42571_-n_0000000004) am no longer a leader.
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.638; 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-09 06:07:45.638; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 1> WARN - 2013-04-09 06:07:45.638; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.661; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.720; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.722; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:46338 46338
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZk2Test-1365487632722
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=21156EF93029B37A -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sr_RS_#Latn -Dtests.timezone=Etc/GMT-7 -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 33.0s J0 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.common.SolrException: Server at http://127.0.0.1:54420/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([21156EF93029B37A:A0F3E0E14776D346]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:375)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4:junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:197)
[junit4:junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:89)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> INFO - 2013-04-09 06:07:45.742; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4] 2> 33030 T1713 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=137), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=137)), sim=DefaultSimilarity, locale=sr_RS_#Latn, timezone=Etc/GMT-7
[junit4:junit4] 2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=3,free=135590992,total=320864256
[junit4:junit4] 2> NOTE: All tests run in this JVM: [LoggingHandlerTest, ShardRoutingTest, LegacyHTMLStripCharFilterTest, ReturnFieldsTest, TestShardHandlerFactory, ChaosMonkeyShardSplitTest, DistributedSpellCheckComponentTest, TestFunctionQuery, TestFaceting, TestDocSet, TestPerFieldSimilarity, TestRandomDVFaceting, MBeansHandlerTest, TestWriterPerf, TestPhraseSuggestions, CircularListTest, SystemInfoHandlerTest, CoreAdminHandlerTest, TestSearchPerf, TestDocumentBuilder, SliceStateUpdateTest, AlternateDirectoryTest, FieldMutatingUpdateProcessorTest, TestExtendedDismaxParser, TestQuerySenderListener, LukeRequestHandlerTest, ScriptEngineTest, QueryEqualityTest, TestIBSimilarityFactory, DocValuesTest, SOLR749Test, QueryElevationComponentTest, TestGroupingSearch, UnloadDistributedZkTest, UpdateRequestProcessorFactoryTest, TestManagedSchema, WordBreakSolrSpellCheckerTest, DistributedTermsComponentTest, TestPHPSerializedResponseWriter, PreAnalyzedFieldTest, SpatialFilterTest, AutoCommitTest, FileBasedSpellCheckerTest, DistributedQueryElevationComponentTest, PreAnalyzedUpdateProcessorTest, SyncSliceTest, MoreLikeThisHandlerTest, SolrIndexSplitterTest, SuggesterFSTTest, SchemaVersionSpecificBehaviorTest, JsonLoaderTest, TestSolrQueryParser, TestReversedWildcardFilterFactory, PrimUtilsTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrDeletionPolicy1, TermVectorComponentTest, TestSweetSpotSimilarityFactory, TestFastLRUCache, CachingDirectoryFactoryTest, TestSchemaSimilarityResource, AnalysisAfterCoreReloadTest, QueryParsingTest, SynonymTokenizerTest, TestPseudoReturnFields, QueryResultKeyTest, TestSchemaNameResource, TestFieldResource, ClusterStateUpdateTest, BasicDistributedZk2Test]
[junit4:junit4] Completed on J0 in 33.56s, 1 test, 1 error <<< FAILURES!
[...truncated 437 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: 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:183: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:448: 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: 287 suites, 1183 tests, 1 error, 1 failure, 13 ignored (7 assumptions)
Total time: 39 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.8.0-ea-b84 -client -XX:+UseG1GC
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_17) - Build #
5084 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5084/
Java: 32bit/jdk1.7.0_17 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest.testWithin {#4 seed=[7DB836996B6A4C58:49C7E98A6C01A087]}
Error Message:
Didn't match org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest$ShapePair@192e709 in Rect(minX=4.0,maxX=230.0,minY=-128.0,maxY=98.0) Expect: [0] (of 1)
Stack Trace:
java.lang.AssertionError: Didn't match org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest$ShapePair@192e709 in Rect(minX=4.0,maxX=230.0,minY=-128.0,maxY=98.0) Expect: [0] (of 1)
at __randomizedtesting.SeedInfo.seed([7DB836996B6A4C58:49C7E98A6C01A087]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest.doTest(SpatialOpRecursivePrefixTreeTest.java:186)
at org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest.testWithin(SpatialOpRecursivePrefixTreeTest.java:83)
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 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 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 7983 lines...]
[junit4:junit4] Suite: org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-2,SPG:(QuadPrefixTree(maxLevels:2,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:4,SPG:(QuadPrefixTree(maxLevels:8,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:4,SPG:(QuadPrefixTree(maxLevels:8,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:4,SPG:(QuadPrefixTree(maxLevels:8,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:2,SPG:(QuadPrefixTree(maxLevels:6,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SpatialOpRecursivePrefixTreeTest -Dtests.method="testWithin {#4 seed=[7DB836996B6A4C58:49C7E98A6C01A087]}" -Dtests.seed=7DB836996B6A4C58 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=bg_BG -Dtests.timezone=Africa/Khartoum -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 0.12s J0 | SpatialOpRecursivePrefixTreeTest.testWithin {#4 seed=[7DB836996B6A4C58:49C7E98A6C01A087]} <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: Didn't match org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest$ShapePair@192e709 in Rect(minX=4.0,maxX=230.0,minY=-128.0,maxY=98.0) Expect: [0] (of 1)
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([7DB836996B6A4C58:49C7E98A6C01A087]:0)
[junit4:junit4] > at org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest.doTest(SpatialOpRecursivePrefixTreeTest.java:186)
[junit4:junit4] > at org.apache.lucene.spatial.prefix.SpatialOpRecursivePrefixTreeTest.testWithin(SpatialOpRecursivePrefixTreeTest.java:83)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:2,SPG:(QuadPrefixTree(maxLevels:6,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-2,SPG:(QuadPrefixTree(maxLevels:2,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:0,SPG:(QuadPrefixTree(maxLevels:4,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-2,SPG:(QuadPrefixTree(maxLevels:2,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:1,SPG:(QuadPrefixTree(maxLevels:5,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:0,SPG:(QuadPrefixTree(maxLevels:4,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:2,SPG:(QuadPrefixTree(maxLevels:6,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:1,SPG:(QuadPrefixTree(maxLevels:5,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-3,SPG:(QuadPrefixTree(maxLevels:1,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-3,SPG:(QuadPrefixTree(maxLevels:1,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-2,SPG:(QuadPrefixTree(maxLevels:2,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-1,SPG:(QuadPrefixTree(maxLevels:3,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-1,SPG:(QuadPrefixTree(maxLevels:3,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-3,SPG:(QuadPrefixTree(maxLevels:1,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:0,SPG:(QuadPrefixTree(maxLevels:4,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:0,SPG:(QuadPrefixTree(maxLevels:4,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:4,SPG:(QuadPrefixTree(maxLevels:8,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:2,SPG:(QuadPrefixTree(maxLevels:6,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:1,SPG:(QuadPrefixTree(maxLevels:5,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:1,SPG:(QuadPrefixTree(maxLevels:5,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:-2,SPG:(QuadPrefixTree(maxLevels:2,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 1> Strategy: RecursivePrefixTreeStrategy(prefixGridScanLevel:3,SPG:(QuadPrefixTree(maxLevels:7,ctx:SpatialContext{geo=false, calculator=CartesianDistCalc, worldBounds=Rect(minX=0.0,maxX=256.0,minY=-128.0,maxY=128.0)})))
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {id=PostingsFormat(name=MockSep), SpatialOpRecursivePrefixTreeTest=PostingsFormat(name=Memory doPackFST= true)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=bg_BG, timezone=Africa/Khartoum
[junit4:junit4] 2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.7.0_17 (32-bit)/cpus=8,threads=1,free=6764704,total=17215488
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SpatialOpRecursivePrefixTreeTest]
[junit4:junit4] Completed on J0 in 2.36s, 32 tests, 1 failure <<< FAILURES!
[...truncated 41 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:355: 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/lucene/build.xml:548: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1776: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/module-build.xml:61: 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: 13 suites, 64 tests, 1 failure, 2 ignored (2 assumptions)
Total time: 24 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.7.0_17 -client -XX:+UseConcMarkSweepGC
Email was triggered for: Failure
Sending email for trigger: Failure