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/07 04:58:02 UTC

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b83) - Build # 5049 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/5049/
Java: 32bit/jdk1.8.0-ea-b83 -server -XX:+UseSerialGC

2 tests failed.
FAILED:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Server at http://127.0.0.1:45861/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:45861/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([B581520304289643:3467DC1B7377F67F]: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)


FAILED:  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([B581520304289643:3467DC1B7377F67F]: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 8867 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZk2Test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.943; org.apache.solr.BaseDistributedSearchTestCase; Setting hostContext system property: /
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.952; org.apache.solr.SolrTestCaseJ4; ###Starting testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.957; 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-07 02:42:15.961; org.apache.solr.cloud.ZkTestServer$ZKServerMain; Starting server
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.988; org.apache.zookeeper.Environment; Server environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.989; org.apache.zookeeper.Environment; Server environment:host.name=serv1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.989; org.apache.zookeeper.Environment; Server environment:java.version=1.8.0-ea
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.989; org.apache.zookeeper.Environment; Server environment:java.vendor=Oracle Corporation
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.990; org.apache.zookeeper.Environment; Server environment:java.home=/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b83/jre
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.990; org.apache.zookeeper.Environment; Server environment:java.class.path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/classes/test:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/codecs/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/common/lucene-analyzers-common-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/codecs/lucene-codecs-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/highlighter/lucene-highlighter-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/memory/lucene-memory-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/misc/lucene-misc-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/spatial/lucene-spatial-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/suggest/lucene-suggest-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/grouping/lucene-grouping-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/queries/lucene-queries-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/queryparser/lucene-queryparser-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/cglib-nodep-2.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-cli-1.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-codec-1.7.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-fileupload-1.2.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-lang-2.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/easymock-3.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/guava-13.0.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/javax.servlet-api-3.0.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/objenesis-1.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/org.restlet-2.1.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/spatial4j-0.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/commons-io-2.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpclient-4.2.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpcore-4.2.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpmime-4.2.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/jcl-over-slf4j-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/jul-to-slf4j-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/log4j-1.2.16.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/noggit-0.5.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/slf4j-api-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/slf4j-log4j12-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/wstx-asl-3.2.7.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/zookeeper-3.4.5.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-continuation-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-deploy-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-http-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-io-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-jmx-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-security-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-server-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-servlet-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-util-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-webapp-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-xml-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/servlet-api-3.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/junit-4.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/randomizedtesting-runner-2.0.9.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/var/lib/jenkins/.ant/lib/ivy-2.3.0.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b83/lib/tools.jar:/var/lib/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.9.jar
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.991; org.apache.zookeeper.Environment; Server environment:java.library.path=/usr/java/packages/lib/i386:/lib:/usr/lib
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.991; org.apache.zookeeper.Environment; Server environment:java.io.tmpdir=.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.992; org.apache.zookeeper.Environment; Server environment:java.compiler=<NA>
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.992; org.apache.zookeeper.Environment; Server environment:os.name=Linux
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.992; org.apache.zookeeper.Environment; Server environment:os.arch=i386
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.992; org.apache.zookeeper.Environment; Server environment:os.version=3.2.0-39-generic
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.993; org.apache.zookeeper.Environment; Server environment:user.name=jenkins
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.993; org.apache.zookeeper.Environment; Server environment:user.home=/var/lib/jenkins
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:15.993; org.apache.zookeeper.Environment; Server environment:user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.010; org.apache.zookeeper.server.ZooKeeperServer; tickTime set to 1000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.010; org.apache.zookeeper.server.ZooKeeperServer; minSessionTimeout set to -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.010; org.apache.zookeeper.server.ZooKeeperServer; maxSessionTimeout set to -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.023; org.apache.zookeeper.server.NIOServerCnxnFactory; binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.060; org.apache.solr.cloud.ZkTestServer; start zk server on port:44846
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.071; org.apache.zookeeper.server.persistence.FileTxnSnapLog; Snapshotting: 0x0 to /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.081; org.apache.zookeeper.Environment; Client environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.082; org.apache.zookeeper.Environment; Client environment:host.name=serv1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.082; org.apache.zookeeper.Environment; Client environment:java.version=1.8.0-ea
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.082; org.apache.zookeeper.Environment; Client environment:java.vendor=Oracle Corporation
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.083; org.apache.zookeeper.Environment; Client environment:java.home=/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b83/jre
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.083; org.apache.zookeeper.Environment; Client environment:java.class.path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/classes/test:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/test-framework/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/codecs/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-solrj/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/common/lucene-analyzers-common-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/codecs/lucene-codecs-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/highlighter/lucene-highlighter-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/memory/lucene-memory-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/misc/lucene-misc-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/spatial/lucene-spatial-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/suggest/lucene-suggest-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/grouping/lucene-grouping-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/queries/lucene-queries-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/queryparser/lucene-queryparser-5.0-SNAPSHOT.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/cglib-nodep-2.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-cli-1.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-codec-1.7.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-fileupload-1.2.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/commons-lang-2.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/easymock-3.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/guava-13.0.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/javax.servlet-api-3.0.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/objenesis-1.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/org.restlet-2.1.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/lib/spatial4j-0.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/commons-io-2.1.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpclient-4.2.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpcore-4.2.2.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/httpmime-4.2.3.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/jcl-over-slf4j-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/jul-to-slf4j-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/log4j-1.2.16.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/noggit-0.5.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/slf4j-api-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/slf4j-log4j12-1.6.6.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/wstx-asl-3.2.7.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/solrj/lib/zookeeper-3.4.5.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-continuation-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-deploy-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-http-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-io-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-jmx-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-security-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-server-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-servlet-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-util-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-webapp-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/jetty-xml-8.1.8.v20121106.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/lib/servlet-api-3.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/build/core/classes/java:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/junit-4.10.jar:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/test-framework/lib/randomizedtesting-runner-2.0.9.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/var/lib/jenkins/.ant/lib/ivy-2.3.0.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/var/lib/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/var/lib/jenkins/tools/java/32bit/jdk1.8.0-ea-b83/lib/tools.jar:/var/lib/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.9.jar
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.084; org.apache.zookeeper.Environment; Client environment:java.library.path=/usr/java/packages/lib/i386:/lib:/usr/lib
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.084; org.apache.zookeeper.Environment; Client environment:java.io.tmpdir=.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.085; org.apache.zookeeper.Environment; Client environment:java.compiler=<NA>
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.086; org.apache.zookeeper.Environment; Client environment:os.name=Linux
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.086; org.apache.zookeeper.Environment; Client environment:os.arch=i386
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.086; org.apache.zookeeper.Environment; Client environment:os.version=3.2.0-39-generic
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.087; org.apache.zookeeper.Environment; Client environment:user.name=jenkins
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.087; org.apache.zookeeper.Environment; Client environment:user.home=/var/lib/jenkins
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.088; org.apache.zookeeper.Environment; Client environment:user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.089; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@14bb822
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.112; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.116; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.119; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.632; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40958
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.644; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40958
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.649; org.apache.zookeeper.server.persistence.FileTxnLog; Creating new log file: log.1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.690; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950000 with negotiated timeout 10000 for client /127.0.0.1:40958
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.690; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950000, negotiated timeout = 10000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.693; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@14bb822 name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.693; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.695; org.apache.solr.common.cloud.SolrZkClient; makePath: /solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.717; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.718; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950000 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.718; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.719; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40958 which had sessionid 0x13de25f67950000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.719; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@eb6d85
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.721; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.721; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.721; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.722; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40959
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.722; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40959
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.723; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950001 with negotiated timeout 10000 for client /127.0.0.1:40959
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.723; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950001, negotiated timeout = 10000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.724; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@eb6d85 name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.724; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.726; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.731; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/shards
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.735; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.740; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/shards
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.746; 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-07 02:42:16.754; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.762; 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-07 02:42:16.763; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.769; 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-07 02:42:16.770; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.774; 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-07 02:42:16.774; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/protwords.txt
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.778; 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-07 02:42:16.779; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.784; 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-07 02:42:16.784; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.788; 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-07 02:42:16.789; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.794; 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-07 02:42:16.794; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.798; 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-07 02:42:16.798; org.apache.solr.common.cloud.SolrZkClient; makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.802; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950001
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.803; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950001 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.803; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40959 which had sessionid 0x13de25f67950001
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:16.803; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.007; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.097; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:44851
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.111; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.112; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.113; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.113; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.114; org.apache.solr.core.CoreContainer; New CoreContainer 3811031
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.114; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.115; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.161; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.162; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.163; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.163; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.163; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.164; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.164; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.165; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.165; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.177; 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-07 02:42:17.590; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.604; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:44846/solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.612; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.613; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@451174
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.614; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.615; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.617; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.617; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40960
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.617; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40960
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.619; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950002 with negotiated timeout 20000 for client /127.0.0.1:40960
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.619; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950002, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.619; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@451174 name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.620; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.622; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950002
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.622; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950002 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.622; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40960 which had sessionid 0x13de25f67950002
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.622; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.624; 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-07 02:42:17.631; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1193544
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.632; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.633; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.633; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.634; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40961
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.634; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40961
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.635; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950003 with negotiated timeout 20000 for client /127.0.0.1:40961
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.635; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950003, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.636; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1193544 name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.636; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.642; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.647; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.649; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/collection-queue-work
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.657; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.659; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44851_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.661; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:44851_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:44851_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.662; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:44851_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.667; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/election
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.680; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.681; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer_elect/leader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.685; org.apache.solr.cloud.Overseer; Overseer (id=89476467004866563-127.0.0.1:44851_-n_0000000000) starting
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.686; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.692; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.694; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.696; org.apache.solr.common.cloud.SolrZkClient; makePath: /overseer/queue-work
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.704; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.706; org.apache.solr.cloud.OverseerCollectionProcessor; Process current queue of collection creations
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.706; org.apache.solr.common.cloud.SolrZkClient; makePath: /clusterstate.json
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.711; org.apache.solr.common.cloud.SolrZkClient; makePath: /aliases.json
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.713; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.724; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Starting to work on the main queue
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.802; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.802; org.apache.solr.cloud.ZkController; Check for collection zkNode:control_collection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.805; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.805; org.apache.solr.cloud.ZkController; Load collection config from:/collections/control_collection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.808; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.809; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.809; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.850; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.906; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.908; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:17.949; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.416; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.427; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.430; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.463; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.472; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.479; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:18.483; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:18.484; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.484; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:18.486; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:18.486; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.487; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.487; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-controljetty-1365302536803/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.488; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.488; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.489; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.489; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:18.490; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.495; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.498; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1fc74e3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1164245)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.498; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.501; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.501; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.502; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.503; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.503; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.504; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.504; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.504; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.505; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.507; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.510; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@8f6442 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.511; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/control/data/tlog
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.511; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.512; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.516; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@8f6442 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.518; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:18.518; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.232; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.233; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:44851_",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:44851"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.233; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection control_collection with numShards 1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.241; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.252; 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-07 02:42:19.520; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.521; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:44851 collection:control_collection shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.526; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.531; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.551; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:delete cxid:0x84 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.552; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.553; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x85 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.559; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.559; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.562; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:44851/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.562; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.563; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:44851/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.563; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:44851/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.564; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:19.572; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950003 type:create cxid:0x90 zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.759; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.776; 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-07 02:42:20.831; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:44851/collection1/ and leader is http://127.0.0.1:44851/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.831; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:44851
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.831; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.832; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.832; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.834; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.837; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.837; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.852; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.860; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.861; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1233392
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.862; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.862; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.863; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.863; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40962
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.864; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40962
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.865; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950004 with negotiated timeout 10000 for client /127.0.0.1:40962
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.865; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950004, negotiated timeout = 10000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.865; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1233392 name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.865; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.867; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.872; org.apache.solr.cloud.ChaosMonkey; monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.934; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.936; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:50126
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.937; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.937; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.938; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.938; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.938; org.apache.solr.core.CoreContainer; New CoreContainer 18602338
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.939; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.939; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.961; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.962; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.962; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.962; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.963; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.963; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.964; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.964; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.964; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.965; 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-07 02:42:20.972; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.993; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:44846/solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.993; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.994; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@129e19f
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.995; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.995; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.996; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.996; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40963
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.996; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40963
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.998; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950005 with negotiated timeout 20000 for client /127.0.0.1:40963
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.998; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950005, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.999; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@129e19f name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:20.999; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.001; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950005
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.001; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950005 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.001; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40963 which had sessionid 0x13de25f67950005
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.001; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.002; 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-07 02:42:21.006; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@49dc6b
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.007; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.007; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.008; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.008; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40964
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.008; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40964
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.009; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950006 with negotiated timeout 20000 for client /127.0.0.1:40964
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.009; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950006, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.010; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@49dc6b name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.010; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.011; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.013; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:21.016; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.021; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50126_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.022; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:delete cxid:0xe zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:50126_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:50126_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.023; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:50126_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.029; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.029; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.029; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.029; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.038; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.038; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.039; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.040; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.041; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.042; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.043; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.082; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.126; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.129; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.167; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.285; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.286; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=1 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"control_collection",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:44851_",
[junit4:junit4]   1>   "numShards":"1",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:44851__collection1",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:44851"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.291; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.291; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.291; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.548; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.558; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.560; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.587; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.592; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.600; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:22.602; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:22.603; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.603; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:22.604; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:22.605; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.605; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.605; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.605; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.606; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.607; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.607; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:22.607; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.607; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.609; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1740a72 lockFactory=org.apache.lucene.store.NativeFSLockFactory@59b85e)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.609; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.611; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.612; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.612; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.613; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.614; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.614; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.614; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.615; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.615; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.618; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.621; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@18fcd46 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.621; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty1/tlog
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.622; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.622; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.627; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@18fcd46 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.630; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:22.630; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.798; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.799; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:50126_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:50126"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.799; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Create collection collection1 with numShards 2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.799; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard shard=shard2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.809; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.809; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:23.809; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.632; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.632; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:50126 collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.634; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.650; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:delete cxid:0x4c zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.651; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.652; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:create cxid:0x4d zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.656; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.656; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.656; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:50126/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.657; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.657; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:50126/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.657; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:50126/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.658; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:24.663; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950006 type:create cxid:0x58 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.317; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.331; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.331; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.331; 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: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.368; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:50126/collection1/ and leader is http://127.0.0.1:50126/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.369; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50126
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.369; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.369; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.369; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.372; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.373; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.373; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.374; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.440; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.443; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:45861
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.443; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.444; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.444; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.444; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.445; org.apache.solr.core.CoreContainer; New CoreContainer 30021679
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.445; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.445; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.468; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.469; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.469; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.469; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.470; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.470; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.470; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.471; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.471; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.471; 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-07 02:42:25.483; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.493; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:44846/solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.493; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.494; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@113580f
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.495; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.495; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.496; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.496; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40966
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.496; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40966
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.497; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950007 with negotiated timeout 20000 for client /127.0.0.1:40966
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.497; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950007, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.498; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@113580f name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.498; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.500; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950007
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.500; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950007 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.501; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40966 which had sessionid 0x13de25f67950007
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.501; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.501; 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-07 02:42:25.505; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@ed365c
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.506; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.506; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.507; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.507; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40967
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.507; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40967
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.508; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950008 with negotiated timeout 20000 for client /127.0.0.1:40967
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.508; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950008, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.509; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@ed365c name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.509; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.510; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.512; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:25.515; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.521; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45861_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.523; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:delete cxid:0xe zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:45861_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:45861_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.524; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:45861_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.529; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.529; org.apache.solr.common.cloud.ZkStateReader$2; A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.530; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.531; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.531; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.533; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.534; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.543; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.543; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.545; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.545; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.547; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.549; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.551; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.593; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.628; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.630; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.669; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.842; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.843; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "node_name":"127.0.0.1:50126_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:50126__collection1",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:50126"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.849; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.849; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.849; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:26.849; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.125; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.140; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.142; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.169; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.174; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.179; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:27.181; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:27.181; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.181; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:27.183; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:27.183; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.184; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.184; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty2-1365302545378/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.184; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.185; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.186; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.186; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:27.186; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.187; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.189; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615d6b lockFactory=org.apache.lucene.store.NativeFSLockFactory@182b6aa)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.189; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.193; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.194; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.195; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.196; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.197; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.197; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.198; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.198; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.199; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.203; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.206; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@64fbb2 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.207; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty2/tlog
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.208; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.208; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.214; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@64fbb2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.216; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:27.216; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.358; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.360; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:45861_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:45861"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.361; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.361; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.369; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.369; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.369; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:28.369; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.218; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.218; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:45861 collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.220; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.227; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:delete cxid:0x4b zxid:0x7d txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard1 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.228; org.apache.solr.cloud.ShardLeaderElectionContext; Running the leader process.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.229; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:create cxid:0x4c zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.231; org.apache.solr.cloud.ShardLeaderElectionContext; Enough replicas found to continue.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.232; org.apache.solr.cloud.ShardLeaderElectionContext; I may be the new leader - try and sync
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.232; org.apache.solr.cloud.SyncStrategy; Sync replicas to http://127.0.0.1:45861/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.232; org.apache.solr.cloud.SyncStrategy; Sync Success - now sync replicas to me
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.232; org.apache.solr.cloud.SyncStrategy; http://127.0.0.1:45861/collection1/ has no replicas
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.232; org.apache.solr.cloud.ShardLeaderElectionContext; I am the new leader: http://127.0.0.1:45861/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.233; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.237; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f67950008 type:create cxid:0x56 zxid:0x81 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.877; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.887; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.888; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.887; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.887; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.891; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:45861/collection1/ and leader is http://127.0.0.1:45861/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.891; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45861
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.891; org.apache.solr.cloud.ZkController; I am the leader, no recovery necessary
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.891; org.apache.solr.cloud.ZkController; publishing core=collection1 state=active
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.892; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.893; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.895; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.895; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.895; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.959; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.961; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:34428
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.962; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.962; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.962; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.963; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.963; org.apache.solr.core.CoreContainer; New CoreContainer 1014248
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.964; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.964; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.989; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.990; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.990; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.991; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.991; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.991; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.992; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.992; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.992; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:29.993; 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-07 02:42:29.999; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.009; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:44846/solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.009; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.010; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@730ee9
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.010; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.011; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.012; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.012; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40968
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.012; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40968
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.013; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f67950009 with negotiated timeout 20000 for client /127.0.0.1:40968
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.013; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f67950009, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.013; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@730ee9 name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.014; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.015; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f67950009
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.016; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f67950009 closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.016; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40968 which had sessionid 0x13de25f67950009
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.016; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.016; 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-07 02:42:30.020; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1d92cf6
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.021; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.021; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.022; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.022; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40969
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.022; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40969
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.023; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f6795000a with negotiated timeout 20000 for client /127.0.0.1:40969
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.023; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f6795000a, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.024; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@1d92cf6 name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.024; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.025; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000a type:create cxid:0x1 zxid:0x8e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.027; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000a type:create cxid:0x3 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:30.030; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.034; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34428_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.035; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000a type:delete cxid:0xe zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:34428_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:34428_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.036; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:34428_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.039; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.039; 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: 3)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.040; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.040; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.041; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.040; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.041; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.043; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.043; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.048; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.049; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.049; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.050; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.051; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.052; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.052; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.086; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.121; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.123; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.147; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.396; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.397; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard1",
[junit4:junit4]   1>   "node_name":"127.0.0.1:45861_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"active",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:45861__collection1",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:45861"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.402; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.402; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.402; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.402; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.403; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.569; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.578; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.581; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.607; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.611; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.616; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:31.618; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:31.619; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.619; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:31.622; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:31.622; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.622; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.622; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty3-1365302549899/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.623; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.623; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.624; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.624; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:31.624; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.624; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.626; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c8f42 lockFactory=org.apache.lucene.store.NativeFSLockFactory@40713f)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.626; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.628; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.628; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.629; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.629; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.630; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.630; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.630; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.631; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.631; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.634; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.637; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@ea7770 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.638; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty3/tlog
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.638; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.639; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.645; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@ea7770 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.648; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:31.648; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.910; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.911; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:34428_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:34428"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.912; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.912; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard shard=shard2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.943; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.943; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.943; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.943; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:32.943; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.650; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.650; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:34428 collection:collection1 shard:shard2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.655; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:34428/collection1/ and leader is http://127.0.0.1:50126/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.655; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34428
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.655; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.656; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.659; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.660; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.660; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.660; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.660; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.662; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.662; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.662; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.663; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.771; org.eclipse.jetty.server.Server; jetty-8.1.8.v20121106
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.774; org.eclipse.jetty.server.AbstractConnector; Started SelectChannelConnector@127.0.0.1:43386
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.775; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init()
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.775; org.apache.solr.core.SolrResourceLoader; JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.776; org.apache.solr.core.SolrResourceLoader; using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.776; org.apache.solr.core.CoreContainer$Initializer; looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/solr.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.777; org.apache.solr.core.CoreContainer; New CoreContainer 9083765
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.777; org.apache.solr.core.CoreContainer; Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.778; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.801; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting socketTimeout to: 120000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.802; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting urlScheme to: http://
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.802; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting connTimeout to: 15000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.802; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxConnectionsPerHost to: 20
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.803; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting corePoolSize to: 0
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.803; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maximumPoolSize to: 2147483647
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.803; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting maxThreadIdleTime to: 5
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.804; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting sizeOfQueue to: -1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.804; org.apache.solr.handler.component.HttpShardHandlerFactory; Setting fairnessPolicy to: false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.804; 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-07 02:42:33.811; org.apache.solr.core.CoreContainer; Registering Log Listener
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.826; org.apache.solr.core.CoreContainer; Zookeeper client=127.0.0.1:44846/solr
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.826; org.apache.solr.cloud.ZkController; zkHost includes chroot
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.827; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@ec6353
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.828; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.828; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.829; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.829; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40970
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.829; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40970
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.830; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f6795000b with negotiated timeout 20000 for client /127.0.0.1:40970
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.830; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f6795000b, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.831; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@ec6353 name:ZooKeeperConnection Watcher:127.0.0.1:44846 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.831; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.833; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de25f6795000b
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.834; org.apache.zookeeper.ZooKeeper; Session: 0x13de25f6795000b closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.834; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:40970 which had sessionid 0x13de25f6795000b
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.834; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.834; 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-07 02:42:33.839; org.apache.zookeeper.ZooKeeper; Initiating client connection, connectString=127.0.0.1:44846/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@56e3c2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.840; org.apache.solr.common.cloud.ConnectionManager; Waiting for client to connect to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.840; org.apache.zookeeper.ClientCnxn$SendThread; Opening socket connection to server localhost.localdomain/127.0.0.1:44846. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.841; org.apache.zookeeper.ClientCnxn$SendThread; Socket connection established to localhost.localdomain/127.0.0.1:44846, initiating session
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.841; org.apache.zookeeper.server.NIOServerCnxnFactory; Accepted socket connection from /127.0.0.1:40971
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.841; org.apache.zookeeper.server.ZooKeeperServer; Client attempting to establish new session at /127.0.0.1:40971
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.842; org.apache.zookeeper.server.ZooKeeperServer; Established session 0x13de25f6795000c with negotiated timeout 20000 for client /127.0.0.1:40971
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.842; org.apache.zookeeper.ClientCnxn$SendThread; Session establishment complete on server localhost.localdomain/127.0.0.1:44846, sessionid = 0x13de25f6795000c, negotiated timeout = 20000
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.843; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@56e3c2 name:ZooKeeperConnection Watcher:127.0.0.1:44846/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.843; org.apache.solr.common.cloud.ConnectionManager; Client is connected to ZooKeeper
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.844; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.846; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000c type:create cxid:0x3 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:33.849; org.apache.solr.common.cloud.ZkStateReader; Updating cluster state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.450; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.452; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":"shard2",
[junit4:junit4]   1>   "node_name":"127.0.0.1:34428_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"recovering",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":"127.0.0.1:34428__collection1",
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:34428"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.462; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.462; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.462; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.462; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.462; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.463; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.854; org.apache.solr.cloud.ZkController; Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43386_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.856; org.apache.zookeeper.server.PrepRequestProcessor; Got user-level KeeperException when processing sessionid:0x13de25f6795000c type:delete cxid:0x10 zxid:0xa7 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:43386_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:43386_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.857; org.apache.solr.common.cloud.SolrZkClient; makePath: /live_nodes/127.0.0.1:43386_
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.861; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.862; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.861; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.862; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.865; 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: 5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.862; 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: 4)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.865; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.866; 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: 5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.867; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.867; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.866; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.869; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (5)
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.886; org.apache.solr.core.CoreContainer; Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.887; org.apache.solr.cloud.ZkController; Check for collection zkNode:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.888; org.apache.solr.cloud.ZkController; Collection zkNode exists
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.889; org.apache.solr.cloud.ZkController; Load collection config from:/collections/collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.890; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/collection1/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.891; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/collection1/lib/README' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.892; org.apache.solr.core.SolrResourceLoader; Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/collection1/lib/classes/' to classloader
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.929; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.969; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.971; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:34.992; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.053; org.apache.solr.servlet.SolrDispatchFilter; [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:34428_&version=2&core=collection1&checkLive=true&coreNodeName=127.0.0.1:34428__collection1&action=PREPRECOVERY&state=recovering&wt=javabin&onlyIfLeader=true} status=0 QTime=1001 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.386; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.396; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.399; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.426; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.431; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.435; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:35.437; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:35.437; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.437; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:35.439; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:35.439; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.439; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.439; org.apache.solr.core.SolrCore; [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty4-1365302553668/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.440; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.440; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.440; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.441; org.apache.solr.core.SolrCore; New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:35.441; org.apache.solr.core.SolrCore; [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.441; org.apache.solr.core.CachingDirectoryFactory; return new directory for ./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.442; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fe1663 lockFactory=org.apache.lucene.store.NativeFSLockFactory@e21ccc)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.443; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.445; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.445; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.445; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.446; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.446; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.446; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.447; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.447; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.448; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.450; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.452; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@834d76 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.453; org.apache.solr.update.UpdateHandler; Clearing tlog files, tlogDir=./org.apache.solr.cloud.BasicDistributedZk2Test-1365302535953/jetty4/tlog
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.453; org.apache.solr.update.CommitTracker; Hard AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.453; org.apache.solr.update.CommitTracker; Soft AutoCommit: disabled
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.457; org.apache.solr.core.SolrCore; [collection1] Registered new searcher Searcher@834d76 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.459; org.apache.solr.cloud.ZkController; publishing core=collection1 state=down
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.459; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.971; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.973; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Update state numShards=2 message={
[junit4:junit4]   1>   "core":"collection1",
[junit4:junit4]   1>   "collection":"collection1",
[junit4:junit4]   1>   "shard":null,
[junit4:junit4]   1>   "node_name":"127.0.0.1:43386_",
[junit4:junit4]   1>   "numShards":"2",
[junit4:junit4]   1>   "roles":null,
[junit4:junit4]   1>   "state":"down",
[junit4:junit4]   1>   "operation":"state",
[junit4:junit4]   1>   "core_node_name":null,
[junit4:junit4]   1>   "base_url":"http://127.0.0.1:43386"}
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.973; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Collection already exists with numShards=2
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.974; org.apache.solr.cloud.Overseer$ClusterStateUpdater; Assigning new node to shard shard=shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:35.981; 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-07 02:42:35.981; 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-07 02:42:35.982; 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-07 02:42:35.981; 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-07 02:42:35.981; 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-07 02:42:35.981; 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-07 02:42:36.461; org.apache.solr.core.CoreContainer; registering core: collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.462; org.apache.solr.cloud.ZkController; Register replica - core:collection1 address:http://127.0.0.1:43386 collection:collection1 shard:shard1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.466; org.apache.solr.cloud.ZkController; We are http://127.0.0.1:43386/collection1/ and leader is http://127.0.0.1:45861/collection1/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.466; org.apache.solr.cloud.ZkController; No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43386
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.466; org.apache.solr.cloud.ZkController; Core needs to recover:collection1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.466; org.apache.solr.update.DefaultSolrCoreState; Running recovery - first canceling any ongoing recovery
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.467; org.apache.solr.cloud.RecoveryStrategy; Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.473; org.apache.solr.cloud.RecoveryStrategy; ###### startupVersions=[]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.473; org.apache.solr.cloud.ZkController; publishing core=collection1 state=recovering
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.473; org.apache.solr.cloud.ZkController; numShards not found on descriptor - reading it from system property
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.473; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.475; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.475; org.apache.solr.servlet.SolrDispatchFilter; user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.476; org.apache.solr.servlet.SolrDispatchFilter; SolrDispatchFilter.init() done
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.476; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.481; org.apache.solr.common.cloud.ZkStateReader; Updating cloud state from ZooKeeper... 
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.484; org.apache.solr.client.solrj.impl.HttpClientUtil; Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.490; org.apache.solr.core.CoreContainer; Creating SolrCore 'onenodecollectioncore' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/onenodecollectioncore
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.490; org.apache.solr.cloud.ZkController; Check for collection zkNode:onenodecollection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.491; org.apache.solr.cloud.ZkController; Creating collection in ZooKeeper:onenodecollection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.492; org.apache.solr.cloud.ZkController; Looking for collection configName
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.493; org.apache.solr.cloud.ZkController; Only one config set found in zk - using it:conf1
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.494; org.apache.solr.common.cloud.SolrZkClient; makePath: /collections/onenodecollection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.497; org.apache.solr.cloud.ZkController; Load collection config from:/collections/onenodecollection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.498; org.apache.solr.core.SolrResourceLoader; new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/onenodecollectioncore/'
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.527; org.apache.solr.core.SolrConfig; Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.568; org.apache.solr.core.SolrConfig; Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.570; org.apache.solr.schema.IndexSchema; Reading Solr Schema from schema.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.585; org.apache.solr.schema.IndexSchema; Schema name=test
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.947; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.955; org.apache.solr.schema.IndexSchema; default search field in schema is text
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.957; org.apache.solr.schema.IndexSchema; unique key field: id
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.981; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.985; org.apache.solr.schema.FileExchangeRateProvider; Reloading exchange rates from file currency.xml
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.989; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:36.990; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:36.991; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.991; org.apache.solr.schema.OpenExchangeRatesOrgProvider; Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:36.993; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Unknown key IMPORTANT NOTE
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:36.993; org.apache.solr.schema.OpenExchangeRatesOrgProvider$OpenExchangeRates; Expected key, got STRING
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.993; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.994; org.apache.solr.core.SolrCore; [onenodecollectioncore] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.BasicDistributedZk2Test-jetty1-1365302540873/onenodecollectioncore/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365302535953/onenodecollection/
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.994; org.apache.solr.core.JmxMonitoredMap; JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@d26282
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.995; org.apache.solr.core.SolrCore; org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.995; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365302535953/onenodecollection
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.996; org.apache.solr.core.SolrCore; New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365302535953/onenodecollection/index/
[junit4:junit4]   1> WARN  - 2013-04-07 02:42:36.996; org.apache.solr.core.SolrCore; [onenodecollectioncore] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365302535953/onenodecollection/index' doesn't exist. Creating new index...
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.996; org.apache.solr.core.CachingDirectoryFactory; return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-BasicDistributedZk2Test-1365302535953/onenodecollection/index
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.998; org.apache.solr.core.SolrDeletionPolicy; SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   1> 	commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@128ab8a lockFactory=org.apache.lucene.store.NativeFSLockFactory@1051355)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:36.998; org.apache.solr.core.SolrDeletionPolicy; newest commit = 1[segments_1]
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.000; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.000; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.001; org.apache.solr.update.processor.UpdateRequestProcessorChain; inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.001; org.apache.solr.core.RequestHandlers; created standard: solr.StandardRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.002; org.apache.solr.core.RequestHandlers; created /get: solr.RealTimeGetHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.002; org.apache.solr.core.RequestHandlers; adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.003; org.apache.solr.core.RequestHandlers; created /replication: solr.ReplicationHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.003; org.apache.solr.core.RequestHandlers; created /update: solr.UpdateRequestHandler
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.003; org.apache.solr.core.RequestHandlers; created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.006; org.apache.solr.handler.loader.XMLLoader; xsltCacheLifetimeSeconds=60
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.008; org.apache.solr.search.SolrIndexSearcher; Opening Searcher@10578f0 main
[junit4:junit4]   1> INFO  - 2013-04-07 02:42:37.009; org.apache.solr.update.UpdateHandler; Clea

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

it4:junit4]   1> INFO  - 2013-04-07 02:52:06.372; org.apache.solr.cloud.Overseer$ClusterStateUpdater; According to ZK I (id=89476496658530316-127.0.0.1:55578_p%2Fxh-n_0000000004) am no longer a leader.
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.374; org.apache.zookeeper.server.PrepRequestProcessor; Processed session termination for sessionid: 0x13de2664f14000c
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.376; 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> INFO  - 2013-04-07 02:52:06.376; 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> INFO  - 2013-04-07 02:52:06.376; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:58454 which had sessionid 0x13de2664f14000c
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.376; org.apache.zookeeper.ZooKeeper; Session: 0x13de2664f14000c closed
[junit4:junit4]   1> WARN  - 2013-04-07 02:52:06.377; org.apache.solr.common.cloud.ZkStateReader$2; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> WARN  - 2013-04-07 02:52:06.379; org.apache.solr.common.cloud.ZkStateReader$3; ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.379; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.380; org.apache.solr.common.cloud.ZkStateReader$3; Updating live nodes... (0)
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.400; org.eclipse.jetty.server.handler.ContextHandler; stopped o.e.j.s.ServletContextHandler{/p/xh,null}
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.454; org.apache.solr.SolrTestCaseJ4; ###Ending testDistribSearch
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.455; org.apache.zookeeper.server.ZooKeeperServer; shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.455; org.apache.zookeeper.server.SessionTrackerImpl; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.456; org.apache.zookeeper.server.PrepRequestProcessor; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.457; org.apache.zookeeper.server.SyncRequestProcessor; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.457; org.apache.zookeeper.server.PrepRequestProcessor; PrepRequestProcessor exited loop!
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.457; org.apache.zookeeper.server.SyncRequestProcessor; SyncRequestProcessor exited!
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.459; org.apache.zookeeper.server.FinalRequestProcessor; shutdown of request processor complete
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.461; org.apache.solr.cloud.ZkTestServer; connecting to 127.0.0.1:49490 49490
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.463; org.apache.zookeeper.server.NIOServerCnxn; Closed socket connection for client /127.0.0.1:58459 which had sessionid 0x13de2664f14000d
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.464; org.apache.zookeeper.ClientCnxn$SendThread; Unable to read additional data from server sessionid 0x13de2664f14000d, likely server has closed socket, closing socket connection and attempting reconnect
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.464; org.apache.zookeeper.server.NIOServerCnxnFactory; NIOServerCnxn factory exited run method
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.464; org.apache.zookeeper.server.ZooKeeperServer; shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.465; org.apache.zookeeper.server.SessionTrackerImpl; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.466; org.apache.zookeeper.server.PrepRequestProcessor; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.466; org.apache.zookeeper.server.SyncRequestProcessor; Shutting down
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.467; org.apache.zookeeper.server.FinalRequestProcessor; shutdown of request processor complete
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.564; org.apache.zookeeper.ZooKeeper; Session: 0x13de2664f14000d closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.564; org.apache.solr.common.cloud.ConnectionManager; Watcher org.apache.solr.common.cloud.ConnectionManager@a7fec name:ZooKeeperConnection Watcher:127.0.0.1:49490/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.565; org.apache.solr.common.cloud.ConnectionManager; Client->ZooKeeper status change trigger but we are already closed
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:06.566; org.apache.zookeeper.ClientCnxn$EventThread; EventThread shut down
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-UnloadDistributedZkTest-1365302988560
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=UnloadDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=B581520304289643 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de_DE -Dtests.timezone=Pacific/Truk -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE  138s J1 | UnloadDistributedZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Still found shard2 in collection test_unload_shard_and_collection
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([B581520304289643:3467DC1B7377F67F]:0)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.testUnloadShardAndCollection(UnloadDistributedZkTest.java:127)
[junit4:junit4]    > 	at org.apache.solr.cloud.UnloadDistributedZkTest.doTest(UnloadDistributedZkTest.java:77)
[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-07 02:52:06.585; org.apache.solr.SolrTestCaseJ4; ###deleteCore
[junit4:junit4]   2> 138041 T1617 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   1> INFO  - 2013-04-07 02:52:07.000; org.apache.zookeeper.server.SessionTrackerImpl; SessionTrackerImpl exited loop!
[junit4:junit4]   2> NOTE: test params are: codec=HighCompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=257), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=HIGH_COMPRESSION, chunkSize=257)), sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=de_DE, timezone=Pacific/Truk
[junit4:junit4]   2> NOTE: Linux 3.2.0-39-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=2,free=30117536,total=200519680
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestStressReorder, BasicDistributedZk2Test, TestCloudManagedSchema, TestAnalyzedSuggestions, SolrPluginUtilsTest, LeaderElectionIntegrationTest, TestIndexSearcher, DirectUpdateHandlerTest, URLClassifyProcessorTest, TestOmitPositions, ClusterStateTest, TestPropInject, DebugComponentTest, OutputWriterTest, PingRequestHandlerTest, SolrIndexConfigTest, TestMultiCoreConfBootstrap, TestNumberUtils, TestDistributedGrouping, SimplePostToolTest, DateMathParserTest, TestMergePolicyConfig, TestJmxMonitoredMap, FieldAnalysisRequestHandlerTest, TestSolrQueryParserDefaultOperatorResource, TestElisionMultitermQuery, NumericFieldsTest, BasicZkTest, TestSolrJ, TestRecovery, NotRequiredUniqueKeyTest, DisMaxRequestHandlerTest, TestSolrQueryParserResource, NoCacheHeaderTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSuggestSpellingConverter, TestCSVLoader, TestSchemaNameResource, TestZkChroot, TestDynamicFieldCollectionResource, TestRandomFaceting, TestBinaryField, TestIndexingPerformance, DefaultValueUpdateProcessorTest, SolrCoreCheckLockOnStartupTest, TestBinaryResponseWriter, XmlUpdateRequestHandlerTest, CurrencyFieldOpenExchangeTest, TestFastOutputStream, SpellCheckCollatorTest, SpellPossibilityIteratorTest, CopyFieldTest, SignatureUpdateProcessorFactoryTest, TestJmxIntegration, TestSchemaResource, TestQuerySenderNoQuery, SortByFunctionTest, TestCSVResponseWriter, OpenExchangeRatesOrgProviderTest, EchoParamsTest, DistanceFunctionTest, TestComponentsName, TestLMJelinekMercerSimilarityFactory, TestCollationField, IndexBasedSpellCheckerTest, CachingDirectoryFactoryTest, TestRTGBase, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest]
[junit4:junit4] Completed on J1 in 138.57s, 1 test, 1 failure <<< FAILURES!

[...truncated 442 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: 285 suites, 1181 tests, 1 error, 1 failure, 13 ignored (7 assumptions)

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