You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/02/03 08:48:32 UTC
[JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 960 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/960/
2 tests failed.
REGRESSION: org.apache.solr.cloud.BasicDistributedZkTest.testDistribSearch
Error Message:
Test abandoned because suite timeout was reached.
Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
at __randomizedtesting.SeedInfo.seed([F4D6429CDFD7C04C]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.BasicDistributedZkTest
Error Message:
Suite timeout exceeded (>= 7200000 msec).
Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
at __randomizedtesting.SeedInfo.seed([F4D6429CDFD7C04C]:0)
Build Log:
[...truncated 9310 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
[junit4:junit4] 2> 1 T592 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 6 T592 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-BasicDistributedZkTest-1359870465609
[junit4:junit4] 2> 16 T592 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 23 T593 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:host.name=lucene.zones.apache.org
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:java.version=1.7.0_09
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:java.home=/usr/local/openjdk7/jre
[junit4:junit4] 2> 97 T593 oaz.Environment.logEnv Server environment:java.class.path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/classes/test:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-test-framework/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/test-framework/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/codecs/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-solrj/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/common/lucene-analyzers-common-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/highlighter/lucene-highlighter-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/memory/lucene-memory-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/misc/lucene-misc-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/spatial/lucene-spatial-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/suggest/lucene-suggest-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/grouping/lucene-grouping-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/queries/lucene-queries-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/queryparser/lucene-queryparser-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/cglib-nodep-2.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-cli-1.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-codec-1.7.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-fileupload-1.2.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-lang-2.6.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/easymock-3.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/guava-13.0.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/javax.servlet-api-3.0.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/objenesis-1.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/spatial4j-0.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/commons-io-2.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpclient-4.1.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpcore-4.1.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpmime-4.1.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/jcl-over-slf4j-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/slf4j-api-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/slf4j-jdk14-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/wstx-asl-3.2.7.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/zookeeper-3.4.5.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-continuation-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-deploy-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-http-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-io-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-jmx-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-security-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-server-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-servlet-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-util-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-webapp-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-xml-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/servlet-api-3.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/core/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/test-framework/lib/junit-4.10.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/test-framework/lib/randomizedtesting-runner-2.0.8.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-launcher.jar:/home/hudson/.ant/lib/ivy-2.2.0.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-logging.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-regexp.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-oro.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-swing.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jdepend.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-xalan2.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bsf.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit4.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-net.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-antlr.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jmf.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-netrexx.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-log4j.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-resolver.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jsch.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-testutil.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bcel.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jai.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-javamail.jar:/usr/local/openjdk7/lib/tools.jar:/home/hudson/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.8.jar
[junit4:junit4] 2> 98 T593 oaz.Environment.logEnv Server environment:java.library.path=/usr/local/openjdk7/jre/lib/amd64/server:/usr/local/openjdk7/jre/lib/amd64:/usr/local/openjdk7/jre/../lib/amd64:/usr/local/openjdk6/jre/lib/amd64/server:/usr/local/openjdk6/jre/lib/amd64:/usr/local/openjdk6/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib:/usr/local/lib
[junit4:junit4] 2> 98 T593 oaz.Environment.logEnv Server environment:java.io.tmpdir=.
[junit4:junit4] 2> 98 T593 oaz.Environment.logEnv Server environment:java.compiler=<NA>
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:os.name=FreeBSD
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:os.arch=amd64
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:os.version=9.0-RELEASE
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:user.name=hudson
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:user.home=/home/hudson
[junit4:junit4] 2> 99 T593 oaz.Environment.logEnv Server environment:user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 141 T593 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 141 T593 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 141 T593 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 148 T593 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 210 T593 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 224 T592 oasc.ZkTestServer.run start zk server on port:16351
[junit4:junit4] 2> 345 T592 oaz.Environment.logEnv Client environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 346 T592 oaz.Environment.logEnv Client environment:host.name=lucene.zones.apache.org
[junit4:junit4] 2> 347 T592 oaz.Environment.logEnv Client environment:java.version=1.7.0_09
[junit4:junit4] 2> 347 T592 oaz.Environment.logEnv Client environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 348 T592 oaz.Environment.logEnv Client environment:java.home=/usr/local/openjdk7/jre
[junit4:junit4] 2> 348 T592 oaz.Environment.logEnv Client environment:java.class.path=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/classes/test:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-test-framework/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/test-framework/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/codecs/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-solrj/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/common/lucene-analyzers-common-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/highlighter/lucene-highlighter-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/memory/lucene-memory-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/misc/lucene-misc-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/spatial/lucene-spatial-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/suggest/lucene-suggest-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/grouping/lucene-grouping-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/queries/lucene-queries-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/queryparser/lucene-queryparser-4.2-SNAPSHOT.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/cglib-nodep-2.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-cli-1.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-codec-1.7.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-fileupload-1.2.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/commons-lang-2.6.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/easymock-3.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/guava-13.0.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/javax.servlet-api-3.0.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/objenesis-1.2.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/core/lib/spatial4j-0.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/commons-io-2.1.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpclient-4.1.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpcore-4.1.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/httpmime-4.1.3.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/jcl-over-slf4j-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/slf4j-api-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/slf4j-jdk14-1.6.4.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/wstx-asl-3.2.7.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/solrj/lib/zookeeper-3.4.5.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-continuation-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-deploy-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-http-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-io-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-jmx-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-security-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-server-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-servlet-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-util-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-webapp-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/jetty-xml-8.1.8.v20121106.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/lib/servlet-api-3.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/build/core/classes/java:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/test-framework/lib/junit-4.10.jar:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/test-framework/lib/randomizedtesting-runner-2.0.8.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-launcher.jar:/home/hudson/.ant/lib/ivy-2.2.0.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-logging.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-regexp.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-oro.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-swing.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jdepend.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-xalan2.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bsf.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit4.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-commons-net.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-antlr.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-junit.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jmf.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-netrexx.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-log4j.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-resolver.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jsch.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-testutil.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-apache-bcel.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-jai.jar:/home/hudson/hudson-slave/tools/hudson.tasks.Ant_AntInstallation/ant-1.8.2/lib/ant-javamail.jar:/usr/local/openjdk7/lib/tools.jar:/home/hudson/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.8.jar
[junit4:junit4] 2> 350 T592 oaz.Environment.logEnv Client environment:java.library.path=/usr/local/openjdk7/jre/lib/amd64/server:/usr/local/openjdk7/jre/lib/amd64:/usr/local/openjdk7/jre/../lib/amd64:/usr/local/openjdk6/jre/lib/amd64/server:/usr/local/openjdk6/jre/lib/amd64:/usr/local/openjdk6/jre/../lib/amd64:/usr/java/packages/lib/amd64:/lib:/usr/lib:/usr/local/lib
[junit4:junit4] 2> 350 T592 oaz.Environment.logEnv Client environment:java.io.tmpdir=.
[junit4:junit4] 2> 351 T592 oaz.Environment.logEnv Client environment:java.compiler=<NA>
[junit4:junit4] 2> 351 T592 oaz.Environment.logEnv Client environment:os.name=FreeBSD
[junit4:junit4] 2> 352 T592 oaz.Environment.logEnv Client environment:os.arch=amd64
[junit4:junit4] 2> 352 T592 oaz.Environment.logEnv Client environment:os.version=9.0-RELEASE
[junit4:junit4] 2> 352 T592 oaz.Environment.logEnv Client environment:user.name=hudson
[junit4:junit4] 2> 353 T592 oaz.Environment.logEnv Client environment:user.home=/home/hudson
[junit4:junit4] 2> 353 T592 oaz.Environment.logEnv Client environment:user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 358 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@24d1358a
[junit4:junit4] 2> 432 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 440 T598 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 442 T598 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 443 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:35417
[junit4:junit4] 2> 463 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:35417
[junit4:junit4] 2> 473 T596 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 542 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300000 with negotiated timeout 10000 for client /140.211.11.196:35417
[junit4:junit4] 2> 543 T598 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300000, negotiated timeout = 10000
[junit4:junit4] 2> 548 T599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24d1358a name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 549 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 553 T592 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 633 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300000
[junit4:junit4] 2> 634 T599 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 634 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300000 closed
[junit4:junit4] 2> 635 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:35417 which had sessionid 0x13c9e9897300000
[junit4:junit4] 2> 634 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@4b7722ad
[junit4:junit4] 2> 636 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 636 T600 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 637 T600 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 637 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:24766
[junit4:junit4] 2> 637 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:24766
[junit4:junit4] 2> 638 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300001 with negotiated timeout 10000 for client /140.211.11.196:24766
[junit4:junit4] 2> 638 T600 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300001, negotiated timeout = 10000
[junit4:junit4] 2> 639 T601 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b7722ad name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 639 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 645 T592 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 651 T592 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 656 T592 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 660 T592 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 665 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 668 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 682 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 684 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 790 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 791 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 796 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 797 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 802 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 803 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 808 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 808 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 813 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 814 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 819 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 820 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 825 T592 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 826 T592 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 831 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300001
[junit4:junit4] 2> 832 T601 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 832 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300001 closed
[junit4:junit4] 2> 832 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:24766 which had sessionid 0x13c9e9897300001
[junit4:junit4] 2> 1010 T592 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 1016 T592 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:38120
[junit4:junit4] 2> 1017 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1018 T592 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1018 T592 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435
[junit4:junit4] 2> 1019 T592 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/solr.xml
[junit4:junit4] 2> 1019 T592 oasc.CoreContainer.<init> New CoreContainer 1328976389
[junit4:junit4] 2> 1020 T592 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/'
[junit4:junit4] 2> 1020 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/'
[junit4:junit4] 2> 1083 T592 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 1084 T592 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1084 T592 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1085 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1085 T592 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1086 T592 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1086 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1087 T592 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1087 T592 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1088 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1113 T592 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 1135 T592 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:16351/solr
[junit4:junit4] 2> 1160 T592 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1161 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@4478c7aa
[junit4:junit4] 2> 1162 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1162 T611 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 1163 T611 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 1164 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:64710
[junit4:junit4] 2> 1164 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:64710
[junit4:junit4] 2> 1170 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300002 with negotiated timeout 20000 for client /140.211.11.196:64710
[junit4:junit4] 2> 1170 T611 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300002, negotiated timeout = 20000
[junit4:junit4] 2> 1171 T612 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4478c7aa name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1171 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1173 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300002
[junit4:junit4] 2> 1240 T612 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 1240 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:64710 which had sessionid 0x13c9e9897300002
[junit4:junit4] 2> 1240 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300002 closed
[junit4:junit4] 2> 1247 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 1265 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3ca519f3
[junit4:junit4] 2> 1266 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1266 T613 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 1267 T613 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 1267 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:14484
[junit4:junit4] 2> 1268 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:14484
[junit4:junit4] 2> 1279 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300003 with negotiated timeout 20000 for client /140.211.11.196:14484
[junit4:junit4] 2> 1280 T613 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300003, negotiated timeout = 20000
[junit4:junit4] 2> 1280 T614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ca519f3 name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1280 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1322 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 1340 T592 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1344 T592 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38120_
[junit4:junit4] 2> 1352 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:delete cxid:0x7 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:38120_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:38120_
[junit4:junit4] 2> 1353 T592 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38120_
[junit4:junit4] 2> 1359 T592 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1393 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:delete cxid:0x15 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 1395 T592 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1399 T592 oasc.Overseer.start Overseer (id=89120470849290243-127.0.0.1:38120_-n_0000000000) starting
[junit4:junit4] 2> 1400 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x1a zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 1434 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x1b zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 1436 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x1c zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 1448 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x1d zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 1450 T616 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1450 T592 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1454 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1478 T615 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1492 T617 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/collection1
[junit4:junit4] 2> 1493 T617 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1494 T617 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1494 T617 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1496 T617 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/collection1/'
[junit4:junit4] 2> 1498 T617 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/collection1/lib/README' to classloader
[junit4:junit4] 2> 1498 T617 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1586 T617 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 1673 T617 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1775 T617 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 1783 T617 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 2539 T617 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2553 T617 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2557 T617 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2580 T617 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2586 T617 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2592 T617 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2594 T617 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2596 T617 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-controljetty-1359870466435/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/
[junit4:junit4] 2> 2596 T617 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e69a380
[junit4:junit4] 2> 2597 T617 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 2598 T617 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data forceNew:false
[junit4:junit4] 2> 2599 T617 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data
[junit4:junit4] 2> 2599 T617 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/index/
[junit4:junit4] 2> 2600 T617 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2602 T617 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/index forceNew:false
[junit4:junit4] 2> 2609 T617 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1e1b315a; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 2609 T617 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 2610 T617 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data/index
[junit4:junit4] 2> 2611 T617 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 2613 T617 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2613 T617 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 2613 T617 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2614 T617 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 2615 T617 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2615 T617 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2615 T617 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2616 T617 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2616 T617 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2617 T617 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 2617 T617 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 2618 T617 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2618 T617 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 2618 T617 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 2619 T617 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 2619 T617 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2620 T617 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2620 T617 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2621 T617 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2621 T617 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2621 T617 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2622 T617 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2622 T617 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2623 T617 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 2623 T617 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 2624 T617 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 2637 T617 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2641 T617 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 2643 T617 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 2646 T617 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/control/data
[junit4:junit4] 2> 2648 T617 oass.SolrIndexSearcher.<init> Opening Searcher@1b9d5463 main
[junit4:junit4] 2> 2649 T617 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2649 T617 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2649 T617 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 2657 T617 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 2706 T618 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b9d5463 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2711 T617 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2711 T617 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2712 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x50 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 2989 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2990 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:38120_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:38120"}
[junit4:junit4] 2> 2990 T615 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 3026 T615 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 3026 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x58 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 3089 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 3725 T617 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 3725 T617 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38120 collection:control_collection shard:shard1
[junit4:junit4] 2> 3737 T617 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 3759 T617 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 3777 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:delete cxid:0x72 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 3784 T617 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 3784 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x73 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3788 T617 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 3788 T617 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 3789 T617 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38120/collection1/
[junit4:junit4] 2> 3789 T617 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 3790 T617 oasc.SyncStrategy.syncToMe http://127.0.0.1:38120/collection1/ has no replicas
[junit4:junit4] 2> 3790 T617 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38120/collection1/
[junit4:junit4] 2> 3790 T617 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 3806 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300003 type:create cxid:0x7d zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4597 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4617 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 4632 T617 oasc.ZkController.register We are http://127.0.0.1:38120/collection1/ and leader is http://127.0.0.1:38120/collection1/
[junit4:junit4] 2> 4632 T617 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38120
[junit4:junit4] 2> 4632 T617 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 4632 T617 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 4633 T617 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 4635 T617 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4636 T592 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 4637 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 4638 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 4652 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 4670 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@f4996dd
[junit4:junit4] 2> 4671 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4671 T619 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4672 T619 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 4672 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29948
[junit4:junit4] 2> 4672 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29948
[junit4:junit4] 2> 4674 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300004 with negotiated timeout 10000 for client /140.211.11.196:29948
[junit4:junit4] 2> 4674 T619 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300004, negotiated timeout = 10000
[junit4:junit4] 2> 4674 T620 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4996dd name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4674 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4676 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4680 T592 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4858 T592 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4861 T592 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29949
[junit4:junit4] 2> 4862 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4863 T592 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4863 T592 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283
[junit4:junit4] 2> 4864 T592 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/solr.xml
[junit4:junit4] 2> 4864 T592 oasc.CoreContainer.<init> New CoreContainer 1596518267
[junit4:junit4] 2> 4865 T592 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/'
[junit4:junit4] 2> 4865 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/'
[junit4:junit4] 2> 4921 T592 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 4922 T592 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4922 T592 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4923 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4923 T592 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4924 T592 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4924 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4924 T592 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4925 T592 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4925 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4950 T592 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4971 T592 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:16351/solr
[junit4:junit4] 2> 4971 T592 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4972 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7455ab21
[junit4:junit4] 2> 4973 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4973 T630 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4974 T630 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 4974 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29950
[junit4:junit4] 2> 4975 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29950
[junit4:junit4] 2> 4977 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300005 with negotiated timeout 20000 for client /140.211.11.196:29950
[junit4:junit4] 2> 4977 T630 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300005, negotiated timeout = 20000
[junit4:junit4] 2> 4977 T631 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7455ab21 name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4977 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4979 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300005
[junit4:junit4] 2> 4988 T631 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4988 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29950 which had sessionid 0x13c9e9897300005
[junit4:junit4] 2> 4988 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300005 closed
[junit4:junit4] 2> 4989 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 5002 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@36f7eb9b
[junit4:junit4] 2> 5003 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 5004 T632 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 5004 T632 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 5005 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29951
[junit4:junit4] 2> 5005 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29951
[junit4:junit4] 2> 5006 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300006 with negotiated timeout 20000 for client /140.211.11.196:29951
[junit4:junit4] 2> 5006 T632 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300006, negotiated timeout = 20000
[junit4:junit4] 2> 5007 T633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36f7eb9b name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 5007 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 5008 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5014 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 5016 T592 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29949_
[junit4:junit4] 2> 5017 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:delete cxid:0x4 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29949_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29949_
[junit4:junit4] 2> 5018 T592 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29949_
[junit4:junit4] 2> 5022 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 5023 T620 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5024 T614 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5032 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5040 T634 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/collection1
[junit4:junit4] 2> 5040 T634 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5041 T634 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5041 T634 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5044 T634 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/collection1/'
[junit4:junit4] 2> 5045 T634 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/collection1/lib/README' to classloader
[junit4:junit4] 2> 5045 T634 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5102 T634 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 5179 T634 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5280 T634 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5288 T634 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5921 T634 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5934 T634 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5938 T634 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5959 T634 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5965 T634 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5970 T634 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5972 T634 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5974 T634 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty1-1359870470283/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/
[junit4:junit4] 2> 5974 T634 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e69a380
[junit4:junit4] 2> 5975 T634 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 5976 T634 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1 forceNew:false
[junit4:junit4] 2> 5976 T634 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1
[junit4:junit4] 2> 5977 T634 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index/
[junit4:junit4] 2> 5977 T634 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5979 T634 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index forceNew:false
[junit4:junit4] 2> 6010 T634 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6ae0c1f; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 6010 T634 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 6011 T634 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index
[junit4:junit4] 2> 6012 T634 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 6014 T634 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 6014 T634 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 6015 T634 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 6015 T634 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 6016 T634 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 6016 T634 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 6016 T634 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 6017 T634 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 6018 T634 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 6018 T634 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 6019 T634 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 6019 T634 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 6020 T634 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 6020 T634 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 6020 T634 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 6021 T634 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 6022 T634 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6022 T634 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6023 T634 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6023 T634 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6024 T634 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6024 T634 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6025 T634 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6026 T634 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 6026 T634 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 6027 T634 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 6045 T634 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 6050 T634 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 6052 T634 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 6055 T634 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1
[junit4:junit4] 2> 6057 T634 oass.SolrIndexSearcher.<init> Opening Searcher@2852f39f main
[junit4:junit4] 2> 6058 T634 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 6058 T634 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 6058 T634 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 6099 T634 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 6132 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6133 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:38120_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:38120"}
[junit4:junit4] 2> 6233 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6233 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6233 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 6415 T635 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2852f39f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 6420 T634 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 6421 T634 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 7793 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7795 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29949_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29949"}
[junit4:junit4] 2> 7795 T615 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 7795 T615 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 7803 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 7803 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 7803 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 8425 T634 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 8425 T634 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29949 collection:collection1 shard:shard1
[junit4:junit4] 2> 8426 T634 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 8447 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:delete cxid:0x45 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 8448 T634 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 8449 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:create cxid:0x46 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8457 T634 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 8457 T634 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 8458 T634 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29949/collection1/
[junit4:junit4] 2> 8458 T634 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 8458 T634 oasc.SyncStrategy.syncToMe http://127.0.0.1:29949/collection1/ has no replicas
[junit4:junit4] 2> 8458 T634 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29949/collection1/
[junit4:junit4] 2> 8459 T634 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 8466 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300006 type:create cxid:0x50 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9316 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9356 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9357 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9357 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9394 T634 oasc.ZkController.register We are http://127.0.0.1:29949/collection1/ and leader is http://127.0.0.1:29949/collection1/
[junit4:junit4] 2> 9394 T634 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29949
[junit4:junit4] 2> 9394 T634 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 9394 T634 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 9395 T634 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 9406 T634 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9408 T592 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 9408 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 9409 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 9607 T592 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 9610 T592 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29961
[junit4:junit4] 2> 9611 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 9611 T592 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 9612 T592 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027
[junit4:junit4] 2> 9612 T592 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/solr.xml
[junit4:junit4] 2> 9613 T592 oasc.CoreContainer.<init> New CoreContainer 2100764407
[junit4:junit4] 2> 9613 T592 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/'
[junit4:junit4] 2> 9614 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/'
[junit4:junit4] 2> 9670 T592 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 9670 T592 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 9671 T592 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 9671 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 9672 T592 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 9672 T592 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 9672 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 9673 T592 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 9673 T592 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 9674 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 9696 T592 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 9716 T592 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:16351/solr
[junit4:junit4] 2> 9716 T592 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 9717 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@4ba08992
[junit4:junit4] 2> 9718 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9719 T645 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9719 T645 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 9720 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29962
[junit4:junit4] 2> 9720 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29962
[junit4:junit4] 2> 9731 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300007 with negotiated timeout 20000 for client /140.211.11.196:29962
[junit4:junit4] 2> 9732 T645 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300007, negotiated timeout = 20000
[junit4:junit4] 2> 9732 T646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ba08992 name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9732 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9734 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300007
[junit4:junit4] 2> 9740 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29962 which had sessionid 0x13c9e9897300007
[junit4:junit4] 2> 9740 T646 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 9740 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300007 closed
[junit4:junit4] 2> 9741 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 9753 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6d9eae8e
[junit4:junit4] 2> 9754 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9754 T647 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9755 T647 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 9755 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29963
[junit4:junit4] 2> 9756 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29963
[junit4:junit4] 2> 9758 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300008 with negotiated timeout 20000 for client /140.211.11.196:29963
[junit4:junit4] 2> 9758 T647 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300008, negotiated timeout = 20000
[junit4:junit4] 2> 9758 T648 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d9eae8e name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9758 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9759 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9761 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9763 T592 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29961_
[junit4:junit4] 2> 9764 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:delete cxid:0x4 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29961_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29961_
[junit4:junit4] 2> 9772 T592 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29961_
[junit4:junit4] 2> 9775 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9775 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9775 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 9778 T620 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9778 T633 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9778 T614 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 9782 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9792 T649 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/collection1
[junit4:junit4] 2> 9792 T649 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9793 T649 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9794 T649 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9796 T649 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/collection1/'
[junit4:junit4] 2> 9798 T649 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9798 T649 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/collection1/lib/README' to classloader
[junit4:junit4] 2> 9880 T649 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 9997 T649 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 10098 T649 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 10106 T649 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10721 T649 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10730 T649 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10733 T649 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10754 T649 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10759 T649 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10812 T649 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10815 T649 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10816 T649 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty2-1359870475027/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/
[junit4:junit4] 2> 10817 T649 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e69a380
[junit4:junit4] 2> 10817 T649 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 10818 T649 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2 forceNew:false
[junit4:junit4] 2> 10818 T649 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2
[junit4:junit4] 2> 10818 T649 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index/
[junit4:junit4] 2> 10819 T649 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10819 T649 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index forceNew:false
[junit4:junit4] 2> 10831 T649 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@73951ff5; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10831 T649 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10832 T649 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index
[junit4:junit4] 2> 10833 T649 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 10834 T649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10834 T649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 10835 T649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10835 T649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 10836 T649 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10836 T649 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10836 T649 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10837 T649 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10837 T649 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10837 T649 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 10838 T649 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 10838 T649 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10838 T649 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 10839 T649 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 10839 T649 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 10839 T649 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10840 T649 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10840 T649 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10840 T649 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10841 T649 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10841 T649 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10842 T649 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10842 T649 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10842 T649 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 10843 T649 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 10843 T649 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 10852 T649 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10855 T649 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 10857 T649 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 10858 T649 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2
[junit4:junit4] 2> 10860 T649 oass.SolrIndexSearcher.<init> Opening Searcher@1d98f986 main
[junit4:junit4] 2> 10860 T649 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10861 T649 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10861 T649 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 10867 T649 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 10879 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10880 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29949_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29949"}
[junit4:junit4] 2> 10900 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10900 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10900 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10900 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 10934 T650 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d98f986 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10937 T649 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10938 T649 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12413 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12414 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29961_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29961"}
[junit4:junit4] 2> 12414 T615 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 12415 T615 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 12452 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12452 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12452 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12452 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 12942 T649 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12942 T649 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29961 collection:collection1 shard:shard2
[junit4:junit4] 2> 12943 T649 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 12965 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:delete cxid:0x44 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4] 2> 12966 T649 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 12967 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:create cxid:0x45 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12977 T649 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 12977 T649 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 12977 T649 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29961/collection1/
[junit4:junit4] 2> 12978 T649 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 12978 T649 oasc.SyncStrategy.syncToMe http://127.0.0.1:29961/collection1/ has no replicas
[junit4:junit4] 2> 12978 T649 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29961/collection1/
[junit4:junit4] 2> 12978 T649 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 12983 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e9897300008 type:create cxid:0x4e zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13968 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13986 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13986 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13986 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 13986 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 14012 T649 oasc.ZkController.register We are http://127.0.0.1:29961/collection1/ and leader is http://127.0.0.1:29961/collection1/
[junit4:junit4] 2> 14012 T649 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29961
[junit4:junit4] 2> 14012 T649 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 14012 T649 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 14013 T649 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14015 T649 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14016 T592 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 14017 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 14017 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 14204 T592 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 14208 T592 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29989
[junit4:junit4] 2> 14208 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 14209 T592 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 14209 T592 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637
[junit4:junit4] 2> 14210 T592 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/solr.xml
[junit4:junit4] 2> 14210 T592 oasc.CoreContainer.<init> New CoreContainer 1068046110
[junit4:junit4] 2> 14211 T592 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/'
[junit4:junit4] 2> 14211 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/'
[junit4:junit4] 2> 14267 T592 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 14267 T592 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 14268 T592 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 14268 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 14269 T592 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 14269 T592 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 14270 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 14270 T592 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 14271 T592 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 14271 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 14295 T592 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 14314 T592 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:16351/solr
[junit4:junit4] 2> 14315 T592 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 14316 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6b1e9c3f
[junit4:junit4] 2> 14317 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 14317 T660 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 14318 T660 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 14318 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29990
[junit4:junit4] 2> 14319 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29990
[junit4:junit4] 2> 14321 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e9897300009 with negotiated timeout 20000 for client /140.211.11.196:29990
[junit4:junit4] 2> 14321 T660 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e9897300009, negotiated timeout = 20000
[junit4:junit4] 2> 14321 T661 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b1e9c3f name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 14322 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 14323 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e9897300009
[junit4:junit4] 2> 14336 T661 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 14336 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29990 which had sessionid 0x13c9e9897300009
[junit4:junit4] 2> 14336 T592 oaz.ZooKeeper.close Session: 0x13c9e9897300009 closed
[junit4:junit4] 2> 14337 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 14350 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2af7e357
[junit4:junit4] 2> 14351 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 14351 T662 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 14352 T662 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 14352 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29991
[junit4:junit4] 2> 14352 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29991
[junit4:junit4] 2> 14354 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e989730000a with negotiated timeout 20000 for client /140.211.11.196:29991
[junit4:junit4] 2> 14354 T662 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e989730000a, negotiated timeout = 20000
[junit4:junit4] 2> 14354 T663 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2af7e357 name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 14354 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 14356 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 14358 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 14365 T592 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29989_
[junit4:junit4] 2> 14366 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000a type:delete cxid:0x4 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29989_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29989_
[junit4:junit4] 2> 14367 T592 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29989_
[junit4:junit4] 2> 14371 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 14371 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 14371 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 14372 T648 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14372 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 14374 T614 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14374 T633 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14374 T620 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 14377 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 14385 T664 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/collection1
[junit4:junit4] 2> 14385 T664 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 14386 T664 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 14386 T664 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 14388 T664 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/collection1/'
[junit4:junit4] 2> 14390 T664 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 14390 T664 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/collection1/lib/README' to classloader
[junit4:junit4] 2> 14444 T664 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 14517 T664 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 14618 T664 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 14625 T664 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 15230 T664 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 15238 T664 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 15241 T664 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 15256 T664 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15261 T664 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15265 T664 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15267 T664 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15268 T664 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty3-1359870479637/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/
[junit4:junit4] 2> 15268 T664 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e69a380
[junit4:junit4] 2> 15269 T664 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 15270 T664 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3 forceNew:false
[junit4:junit4] 2> 15270 T664 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 15271 T664 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index/
[junit4:junit4] 2> 15271 T664 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 15272 T664 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index forceNew:false
[junit4:junit4] 2> 15277 T664 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@23dee70b; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 15277 T664 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 15278 T664 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index
[junit4:junit4] 2> 15278 T664 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 15280 T664 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 15280 T664 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 15280 T664 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 15280 T664 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 15281 T664 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 15281 T664 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 15281 T664 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 15282 T664 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 15282 T664 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 15283 T664 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 15283 T664 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 15283 T664 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 15284 T664 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 15284 T664 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 15284 T664 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 15285 T664 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 15285 T664 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15285 T664 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15286 T664 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15286 T664 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15286 T664 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15287 T664 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15287 T664 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15288 T664 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 15288 T664 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 15289 T664 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 15297 T664 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 15300 T664 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 15302 T664 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 15303 T664 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 15305 T664 oass.SolrIndexSearcher.<init> Opening Searcher@652cc1f5 main
[junit4:junit4] 2> 15305 T664 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 15306 T664 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 15306 T664 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 15311 T664 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 15369 T665 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@652cc1f5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 15373 T664 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 15373 T664 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15501 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15502 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29961_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29961"}
[junit4:junit4] 2> 15508 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29989_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29989"}
[junit4:junit4] 2> 15508 T615 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 15508 T615 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 15521 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15521 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15521 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15521 T663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 15521 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16376 T664 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16376 T664 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29989 collection:collection1 shard:shard1
[junit4:junit4] 2> 16387 T664 oasc.ZkController.register We are http://127.0.0.1:29989/collection1/ and leader is http://127.0.0.1:29949/collection1/
[junit4:junit4] 2> 16388 T664 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29989
[junit4:junit4] 2> 16388 T664 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16388 T664 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@e3e496a url=http://127.0.0.1:29989/collection1 node=127.0.0.1:29989_ C36_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:29989_, base_url=http://127.0.0.1:29989}
[junit4:junit4] 2> 16395 T666 C36 P29989 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16397 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16397 T664 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16397 T666 C36 P29989 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16397 T666 C36 P29989 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16398 T592 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 16399 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16399 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16400 T666 C36 P29989 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16595 T592 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 16599 T592 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29993
[junit4:junit4] 2> 16599 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 16600 T592 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 16600 T592 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024
[junit4:junit4] 2> 16601 T592 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/solr.xml
[junit4:junit4] 2> 16601 T592 oasc.CoreContainer.<init> New CoreContainer 643551151
[junit4:junit4] 2> 16602 T592 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/'
[junit4:junit4] 2> 16602 T592 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/'
[junit4:junit4] 2> 16658 T592 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4] 2> 16659 T592 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 16659 T592 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 16660 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 16660 T592 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 16661 T592 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 16661 T592 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 16662 T592 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 16662 T592 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 16663 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4] 2> 16684 T592 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 16704 T592 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:16351/solr
[junit4:junit4] 2> 16704 T592 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 16705 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@71fb6d3a
[junit4:junit4] 2> 16706 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16707 T676 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 16707 T676 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 16708 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29994
[junit4:junit4] 2> 16708 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29994
[junit4:junit4] 2> 16710 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e989730000b with negotiated timeout 20000 for client /140.211.11.196:29994
[junit4:junit4] 2> 16710 T676 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e989730000b, negotiated timeout = 20000
[junit4:junit4] 2> 16710 T677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71fb6d3a name:ZooKeeperConnection Watcher:127.0.0.1:16351 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16711 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16713 T597 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13c9e989730000b
[junit4:junit4] 2> 16724 T677 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 16724 T594 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29994 which had sessionid 0x13c9e989730000b
[junit4:junit4] 2> 16724 T592 oaz.ZooKeeper.close Session: 0x13c9e989730000b closed
[junit4:junit4] 2> 16725 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4] 2> 16736 T592 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:16351/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@70f6266
[junit4:junit4] 2> 16737 T592 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 16738 T678 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:16351. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 16738 T678 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:16351, initiating session
[junit4:junit4] 2> 16738 T594 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29995
[junit4:junit4] 2> 16739 T594 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29995
[junit4:junit4] 2> 16740 T596 oazs.ZooKeeperServer.finishSessionInit Established session 0x13c9e989730000c with negotiated timeout 20000 for client /140.211.11.196:29995
[junit4:junit4] 2> 16740 T678 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:16351, sessionid = 0x13c9e989730000c, negotiated timeout = 20000
[junit4:junit4] 2> 16741 T679 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@70f6266 name:ZooKeeperConnection Watcher:127.0.0.1:16351/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 16741 T592 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 16742 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000c type:create cxid:0x1 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 16748 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000c type:create cxid:0x2 zxid:0xa2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 16750 T592 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29993_
[junit4:junit4] 2> 16751 T597 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13c9e989730000c type:delete cxid:0x4 zxid:0xa3 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29993_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29993_
[junit4:junit4] 2> 16752 T592 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29993_
[junit4:junit4] 2> 16760 T663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16760 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16760 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16760 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 16761 T648 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16761 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 16763 T663 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16763 T620 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16764 T614 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16764 T633 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 16767 T592 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 16775 T680 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/collection1
[junit4:junit4] 2> 16775 T680 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 16776 T680 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 16776 T680 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 16778 T680 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/collection1/'
[junit4:junit4] 2> 16779 T680 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 16780 T680 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/collection1/lib/README' to classloader
[junit4:junit4] 2> 16834 T680 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 16907 T680 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 17008 T680 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 17015 T680 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 17036 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17037 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29989_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29989"}
[junit4:junit4] 2> 17051 T663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17051 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17051 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17051 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17051 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17051 T679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 17650 T680 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 17658 T680 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 17661 T680 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 17680 T680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 17685 T680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 17689 T680 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 17690 T680 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 17692 T680 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-jetty4-1359870482024/collection1/, dataDir=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/
[junit4:junit4] 2> 17692 T680 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7e69a380
[junit4:junit4] 2> 17692 T680 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4] 2> 17693 T680 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4 forceNew:false
[junit4:junit4] 2> 17694 T680 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4
[junit4:junit4] 2> 17694 T680 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/index/
[junit4:junit4] 2> 17694 T680 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 17695 T680 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/index forceNew:false
[junit4:junit4] 2> 17726 T680 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2cb96766; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 17726 T680 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 17727 T680 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4/index
[junit4:junit4] 2> 17727 T680 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 17729 T680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 17729 T680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 17729 T680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 17729 T680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 17730 T680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 17730 T680 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 17730 T680 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 17731 T680 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 17731 T680 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 17732 T680 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 17732 T680 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 17732 T680 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 17733 T680 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 17733 T680 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 17733 T680 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 17733 T680 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 17734 T680 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17734 T680 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17735 T680 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17735 T680 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17735 T680 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17736 T680 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17736 T680 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17737 T680 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 17737 T680 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 17737 T680 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 17746 T680 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 17749 T680 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 17750 T680 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4] 2> 17752 T680 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty4
[junit4:junit4] 2> 17753 T680 oass.SolrIndexSearcher.<init> Opening Searcher@16338f16 main
[junit4:junit4] 2> 17754 T680 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 17754 T680 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 17754 T680 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 17760 T680 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 17813 T681 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16338f16 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 17817 T680 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 17817 T680 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 18559 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18560 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29993_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29993"}
[junit4:junit4] 2> 18560 T615 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 18560 T615 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4] 2> 18573 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18573 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18573 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18573 T679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18573 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18573 T663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 18820 T680 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 18820 T680 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29993 collection:collection1 shard:shard2
[junit4:junit4] 2> 18824 T680 oasc.ZkController.register We are http://127.0.0.1:29993/collection1/ and leader is http://127.0.0.1:29961/collection1/
[junit4:junit4] 2> 18825 T680 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29993
[junit4:junit4] 2> 18825 T680 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 18825 T680 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@58a79aa3 url=http://127.0.0.1:29993/collection1 node=127.0.0.1:29993_ C37_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:29993_, base_url=http://127.0.0.1:29993}
[junit4:junit4] 2> 18826 T682 C37 P29993 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 18827 T682 C37 P29993 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 18827 T682 C37 P29993 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 18827 T680 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18827 T682 C37 P29993 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 18828 T592 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 18829 T682 C37 P29993 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18829 T592 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 18830 T592 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18852 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 18855 T592 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):230
[junit4:junit4] 2> 18856 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C36_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29989_, base_url=http://127.0.0.1:29989}
[junit4:junit4] 2> 19436 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:29949/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 19446 T666 C36 P29989 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 19464 T666 C36 P29989 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:29989 START replicas=[http://127.0.0.1:29949/collection1/] nUpdates=100
[junit4:junit4] 2> 19465 T666 C36 P29989 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 19466 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 19466 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 19467 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 19467 T666 C36 P29989 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 19467 T666 C36 P29989 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:29949/collection1/. core=collection1
[junit4:junit4] 2> 19467 T666 C36 P29989 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@64fa4d97 url=http://127.0.0.1:29949/collection1 node=127.0.0.1:29949_ C38_STATE=coll:collection1 core:collection1 props:{shard=shard1, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29949_, base_url=http://127.0.0.1:29949, leader=true}
[junit4:junit4] 2> 19478 T624 C38 P29949 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 19498 T625 C38 P29949 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 19499 T625 C38 P29949 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1
[junit4:junit4] 2> 19503 T625 C38 P29949 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6ae0c1f; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 19504 T625 C38 P29949 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 19536 T625 C38 P29949 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6ae0c1f; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6ae0c1f; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19536 T625 C38 P29949 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19537 T625 C38 P29949 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1
[junit4:junit4] 2> 19538 T625 C38 P29949 oass.SolrIndexSearcher.<init> Opening Searcher@33a64e7d realtime
[junit4:junit4] 2> 19538 T625 C38 P29949 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19539 T625 C38 P29949 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 58
[junit4:junit4] 2> 19540 T666 C36 P29989 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19540 T666 C36 P29989 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 19566 T666 C36 P29989 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 19569 T626 C38 P29949 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 19570 T626 C38 P29949 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 19571 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 19571 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 19571 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 19575 T626 C38 P29949 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1
[junit4:junit4] 2> 19575 T626 C38 P29949 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty1/index
[junit4:junit4] 2> 19576 T626 C38 P29949 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2
[junit4:junit4] 2> 19577 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 19578 T666 C36 P29989 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 forceNew:false
[junit4:junit4] 2> 19579 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19580 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Starting download to RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ae2ff9a; maxCacheMB=48.0 maxMergeSizeMB=4.0)) fullCopy=true
[junit4:junit4] 2> 19593 T626 C38 P29949 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=5
[junit4:junit4] 2> 19606 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index
[junit4:junit4] 2> 19607 T666 C36 P29989 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 19607 T666 C36 P29989 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130202204805179
[junit4:junit4] 2> 19609 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19610 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19610 T666 C36 P29989 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index/ new=./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179
[junit4:junit4] 2> 19614 T666 C36 P29989 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ae2ff9a; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19614 T666 C36 P29989 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19616 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19620 T666 C36 P29989 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 19620 T666 C36 P29989 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 19621 T666 C36 P29989 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 19621 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179
[junit4:junit4] 2> 19622 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19626 T666 C36 P29989 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ae2ff9a; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 19626 T666 C36 P29989 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 19626 T666 C36 P29989 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 19627 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19627 T666 C36 P29989 oass.SolrIndexSearcher.<init> Opening Searcher@44825009 main
[junit4:junit4] 2> 19629 T665 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44825009 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 19629 T665 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index
[junit4:junit4] 2> 19630 T666 C36 P29989 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=false,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 19633 T666 C36 P29989 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ae2ff9a; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ae2ff9a; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_3,generation=3,filenames=[segments_3]
[junit4:junit4] 2> 19633 T666 C36 P29989 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[segments_3]
[junit4:junit4] 2> 19634 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3
[junit4:junit4] 2> 19635 T666 C36 P29989 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 19635 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index.20130202204805179
[junit4:junit4] 2> 19635 T666 C36 P29989 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty3/index
[junit4:junit4] 2> 19635 T666 C36 P29989 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 19635 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 19636 T666 C36 P29989 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 19636 T666 C36 P29989 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19643 T666 C36 P29989 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 19859 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20080 T615 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20081 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29993_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29993"}
[junit4:junit4] 2> 20465 T615 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:29989_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:29989"}
[junit4:junit4] 2> 20484 T648 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20484 T679 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20484 T620 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20484 T633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20484 T663 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20484 T614 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 20861 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21865 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C37_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29993_, base_url=http://127.0.0.1:29993}
[junit4:junit4] 2> 22857 T682 C37 P29993 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:29961/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 22857 T682 C37 P29993 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:29993 START replicas=[http://127.0.0.1:29961/collection1/] nUpdates=100
[junit4:junit4] 2> 22858 T682 C37 P29993 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 22858 T682 C37 P29993 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 22858 T682 C37 P29993 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 22858 T682 C37 P29993 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 22859 T682 C37 P29993 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 22859 T682 C37 P29993 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:29961/collection1/. core=collection1
[junit4:junit4] 2> 22859 T682 C37 P29993 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 22867 T592 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C39 name=collection1 org.apache.solr.core.SolrCore@1c63d67e url=http://127.0.0.1:29961/collection1 node=127.0.0.1:29961_ C39_STATE=coll:collection1 core:collection1 props:{shard=shard2, roles=null, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29961_, base_url=http://127.0.0.1:29961, leader=true}
[junit4:junit4] 2> 22877 T639 C39 P29961 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 22885 T640 C39 P29961 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false}
[junit4:junit4] 2> 22886 T640 C39 P29961 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2
[junit4:junit4] 2> 22890 T640 C39 P29961 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@73951ff5; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 22891 T640 C39 P29961 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 22913 T640 C39 P29961 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@73951ff5; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@73951ff5; maxCacheMB=48.0 maxMergeSizeMB=4.0)),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4] 2> 22914 T640 C39 P29961 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4] 2> 22915 T640 C39 P29961 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2
[junit4:junit4] 2> 22915 T640 C39 P29961 oass.SolrIndexSearcher.<init> Opening Searcher@392c9bff realtime
[junit4:junit4] 2> 22916 T640 C39 P29961 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 22916 T640 C39 P29961 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 31
[junit4:junit4] 2> 22917 T682 C37 P29993 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22918 T682 C37 P29993 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 22920 T641 C39 P29961 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 22921 T641 C39 P29961 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 22922 T682 C37 P29993 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 22922 T682 C37 P29993 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 22922 T682 C37 P29993 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 22925 T641 C39 P29961 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2
[junit4:junit4] 2> 22925 T641 C39 P29961 oasc.CachingDirectoryFactory.close Releasing directory:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.BasicDistributedZkTest-1359870465609/jetty2/index
[junit4:junit4] 2> 22926 T641 C39 P29961 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation
[...truncated too long message...]
nputStream.java:121)
[junit4:junit4] 2> at org.eclipse.jetty.io.ByteArrayBuffer.readFrom(ByteArrayBuffer.java:375)
[junit4:junit4] 2> at org.eclipse.jetty.io.bio.StreamEndPoint.fill(StreamEndPoint.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.fill(SocketConnector.java:227)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.fill(HttpParser.java:1035)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:280)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
[junit4:junit4] 2> at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72)
[junit4:junit4] 2> at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 26) Thread[id=667, name=HashSessionScavenger-13, state=TIMED_WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] 2> at java.lang.Object.wait(Native Method)
[junit4:junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:552)
[junit4:junit4] 2> at java.util.TimerThread.run(Timer.java:505)
[junit4:junit4] 2> 27) Thread[id=678, name=TEST-BasicDistributedZkTest.testDistribSearch-seed#[F4D6429CDFD7C04C]-SendThread(localhost:16351), state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:82)
[junit4:junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2> 28) Thread[id=662, name=TEST-BasicDistributedZkTest.testDistribSearch-seed#[F4D6429CDFD7C04C]-SendThread(localhost:16351), state=RUNNABLE, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] 2> at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
[junit4:junit4] 2> at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:159)
[junit4:junit4] 2> at sun.nio.ch.KQueueSelectorImpl.doSelect(KQueueSelectorImpl.java:103)
[junit4:junit4] 2> at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
[junit4:junit4] 2> at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:338)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4] 2> 29) Thread[id=681, name=searcherExecutor-274-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4:junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4:junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 30) Thread[id=725, name=searcherExecutor-290-thread-1, state=WAITING, group=TGRP-BasicDistributedZkTest]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
[junit4:junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
[junit4:junit4] 2> at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1043)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1103)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {n_f1=MockVariableIntBlock(baseBlockSize=31), foo_b=PostingsFormat(name=MockSep), cat=PostingsFormat(name=MockRandom), foo_d=PostingsFormat(name=Memory doPackFST= true), foo_f=PostingsFormat(name=MockSep), n_tl1=MockVariableIntBlock(baseBlockSize=31), n_d1=PostingsFormat(name=MockRandom), rnd_b=PostingsFormat(name=Memory doPackFST= true), intDefault=MockVariableIntBlock(baseBlockSize=31), n_td1=MockVariableIntBlock(baseBlockSize=31), timestamp=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=PostingsFormat(name=Memory doPackFST= true), range_facet_si=PostingsFormat(name=MockRandom), oddField_s=PostingsFormat(name=Memory doPackFST= true), sequence_i=PostingsFormat(name=Memory doPackFST= true), name=PostingsFormat(name=Memory doPackFST= true), foo_i=MockVariableIntBlock(baseBlockSize=31), regex_dup_B_s=PostingsFormat(name=MockRandom), multiDefault=PostingsFormat(name=MockRandom), n_tf1=PostingsFormat(name=MockRandom), n_dt1=MockVariableIntBlock(baseBlockSize=31), genre_s=PostingsFormat(name=Memory doPackFST= true), author_t=MockVariableIntBlock(baseBlockSize=31), n_ti1=PostingsFormat(name=Memory doPackFST= true), range_facet_l=PostingsFormat(name=MockRandom), text=PostingsFormat(name=MockSep), _version_=MockVariableIntBlock(baseBlockSize=31), val_i=PostingsFormat(name=Memory doPackFST= true), SubjectTerms_mfacet=MockVariableIntBlock(baseBlockSize=31), series_t=MockVariableIntBlock(baseBlockSize=31), a_t=PostingsFormat(name=MockRandom), n_tdt1=MockVariableIntBlock(baseBlockSize=31), regex_dup_A_s=PostingsFormat(name=MockSep), price=PostingsFormat(name=MockSep), other_tl1=MockVariableIntBlock(baseBlockSize=31), n_l1=PostingsFormat(name=MockRandom), a_si=MockVariableIntBlock(baseBlockSize=31), inStock=PostingsFormat(name=MockSep)}, sim=DefaultSimilarity, locale=no_NO_NY, timezone=America/Nome
[junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_09 (64-bit)/cpus=16,threads=31,free=190229376,total=419430400
[junit4:junit4] 2> NOTE: All tests run in this JVM: [ResourceLoaderTest, BinaryUpdateRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestLFUCache, SearchHandlerTest, TestBinaryResponseWriter, ChaosMonkeySafeLeaderTest, TestExtendedDismaxParser, SolrPluginUtilsTest, TestJoin, TestSystemIdResolver, TestSolr4Spatial, FieldAnalysisRequestHandlerTest, ChaosMonkeyNothingIsSafeTest, SuggesterFSTTest, TestSuggestSpellingConverter, DirectSolrConnectionTest, TestFastLRUCache, SystemInfoHandlerTest, TestQueryTypes, TestRandomFaceting, TestSolrQueryParser, SpatialFilterTest, TestPerFieldSimilarity, DistanceFunctionTest, TestDocumentBuilder, TestStressVersions, TestDefaultSimilarityFactory, SpellCheckCollatorTest, DistributedSpellCheckComponentTest, SpellCheckComponentTest, CoreAdminHandlerTest, PreAnalyzedFieldTest, LoggingHandlerTest, TestNumberUtils, MBeansHandlerTest, TestGroupingSearch, CSVRequestHandlerTest, CircularListTest, TestFiltering, AlternateDirectoryTest, TestSolrIndexConfig, MoreLikeThisHandlerTest, TestPseudoReturnFields, TestLMDirichletSimilarityFactory, ExternalFileFieldSortTest, TestPartialUpdateDeduplication, MinimalSchemaTest, SimpleFacetsTest, TestFastOutputStream, TestLuceneMatchVersion, BasicDistributedZkTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZkTest -Dtests.seed=F4D6429CDFD7C04C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=no_NO_NY -Dtests.timezone=America/Nome -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 0.00s J0 | BasicDistributedZkTest (suite) <<<
[junit4:junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([F4D6429CDFD7C04C]:0)
[junit4:junit4] Completed on J0 in 7223.67s, 1 test, 2 errors <<< FAILURES!
[...truncated 29 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:346: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build.xml:178: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/common-build.xml:428: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:1176: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:841: There were test failures: 250 suites, 1041 tests, 1 suite-level error, 1 error, 51 ignored (5 assumptions)
Total time: 148 minutes 4 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure