You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/03/09 06:43:17 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_15) - Build #
2633 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2633/
Java: 32bit/jdk1.7.0_15 -server -XX:+UseSerialGC
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.RecoveryZkTest
Error Message:
Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=77, name=coreLoadExecutor-33-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=77, name=coreLoadExecutor-33-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
at java.lang.Thread.getStackTrace(Thread.java:1567)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:266)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:222)
at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:244)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:733)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:874)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:957)
at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:580)
at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:575)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
at java.util.concurrent.FutureTask.run(FutureTask.java:166)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:722)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@13fe0f4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12c2a3)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
... 1 more
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.RecoveryZkTest
Error Message:
Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=79, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
Stack Trace:
com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=79, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
at java.lang.Thread.getStackTrace(Thread.java:1567)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:266)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:222)
at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:383)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:281)
at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:409)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 8805 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 0 T17 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_tl/i
[junit4:junit4] 2> 9 T17 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-RecoveryZkTest-1362805743067
[junit4:junit4] 2> 19 T17 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 25 T18 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 99 T18 oaz.Environment.logEnv Server environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 99 T18 oaz.Environment.logEnv Server environment:host.name=JenkinsSlave-PC
[junit4:junit4] 2> 100 T18 oaz.Environment.logEnv Server environment:java.version=1.7.0_15
[junit4:junit4] 2> 100 T18 oaz.Environment.logEnv Server environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 100 T18 oaz.Environment.logEnv Server environment:java.home=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre
[junit4:junit4] 2> 101 T18 oaz.Environment.logEnv Server environment:java.class.path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\classes\test;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-test-framework\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\test-framework\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\codecs\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\common\lucene-analyzers-common-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\kuromoji\lucene-analyzers-kuromoji-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\phonetic\lucene-analyzers-phonetic-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\codecs\lucene-codecs-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\highlighter\lucene-highlighter-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\memory\lucene-memory-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\misc\lucene-misc-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\spatial\lucene-spatial-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\suggest\lucene-suggest-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\grouping\lucene-grouping-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\queries\lucene-queries-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\queryparser\lucene-queryparser-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\cglib-nodep-2.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-cli-1.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-codec-1.7.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-fileupload-1.2.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-lang-2.6.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\easymock-3.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\guava-13.0.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\javax.servlet-api-3.0.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\objenesis-1.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\org.restlet-2.1.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\org.restlet.ext.servlet-2.1.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\spatial4j-0.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\commons-io-2.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpclient-4.2.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpcore-4.2.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpmime-4.2.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\jcl-over-slf4j-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\slf4j-api-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\slf4j-jdk14-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\wstx-asl-3.2.7.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\zookeeper-3.4.5.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-continuation-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-deploy-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-http-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-io-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-jmx-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-security-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-server-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-servlet-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-util-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-webapp-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-xml-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\servlet-api-3.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\example-DIH\solr\db\lib\derby-10.9.1.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\example-DIH\solr\db\lib\hsqldb-1.8.0.10.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\core\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\test-framework\lib\junit-4.10.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\test-framework\lib\randomizedtesting-runner-2.0.8.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-launcher.jar;C:\Users\JenkinsSlave\.ant\lib\ivy-2.3.0.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-antlr.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-bcel.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-bsf.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-log4j.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-oro.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-regexp.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-resolver.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-xalan2.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-commons-logging.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-commons-net.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jai.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-javamail.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jdepend.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jmf.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jsch.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-junit.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-junit4.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-netrexx.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-swing.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-testutil.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant.jar;C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\lib\tools.jar;C:\Users\JenkinsSlave\.ivy2\cache\com.carrotsearch.randomizedtesting\junit4-ant\jars\junit4-ant-2.0.8.jar
[junit4:junit4] 2> 102 T18 oaz.Environment.logEnv Server environment:java.library.path=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Subversion\bin;.
[junit4:junit4] 2> 102 T18 oaz.Environment.logEnv Server environment:java.io.tmpdir=.
[junit4:junit4] 2> 102 T18 oaz.Environment.logEnv Server environment:java.compiler=<NA>
[junit4:junit4] 2> 103 T18 oaz.Environment.logEnv Server environment:os.name=Windows 7
[junit4:junit4] 2> 104 T18 oaz.Environment.logEnv Server environment:os.arch=x86
[junit4:junit4] 2> 104 T18 oaz.Environment.logEnv Server environment:os.version=6.1
[junit4:junit4] 2> 105 T18 oaz.Environment.logEnv Server environment:user.name=JenkinsSlave
[junit4:junit4] 2> 105 T18 oaz.Environment.logEnv Server environment:user.home=C:\Users\JenkinsSlave
[junit4:junit4] 2> 105 T18 oaz.Environment.logEnv Server environment:user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 139 T18 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 139 T18 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 140 T18 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 144 T18 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 207 T18 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4] 2> 223 T17 oasc.ZkTestServer.run start zk server on port:51322
[junit4:junit4] 2> 304 T17 oaz.Environment.logEnv Client environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 305 T17 oaz.Environment.logEnv Client environment:host.name=JenkinsSlave-PC
[junit4:junit4] 2> 306 T17 oaz.Environment.logEnv Client environment:java.version=1.7.0_15
[junit4:junit4] 2> 306 T17 oaz.Environment.logEnv Client environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 307 T17 oaz.Environment.logEnv Client environment:java.home=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre
[junit4:junit4] 2> 307 T17 oaz.Environment.logEnv Client environment:java.class.path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\classes\test;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-test-framework\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\test-framework\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\codecs\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-solrj\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\common\lucene-analyzers-common-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\kuromoji\lucene-analyzers-kuromoji-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\analysis\phonetic\lucene-analyzers-phonetic-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\codecs\lucene-codecs-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\highlighter\lucene-highlighter-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\memory\lucene-memory-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\misc\lucene-misc-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\spatial\lucene-spatial-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\suggest\lucene-suggest-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\grouping\lucene-grouping-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\queries\lucene-queries-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\queryparser\lucene-queryparser-5.0-SNAPSHOT.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\cglib-nodep-2.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-cli-1.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-codec-1.7.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-fileupload-1.2.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\commons-lang-2.6.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\easymock-3.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\guava-13.0.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\javax.servlet-api-3.0.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\objenesis-1.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\org.restlet-2.1.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\org.restlet.ext.servlet-2.1.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\lib\spatial4j-0.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\commons-io-2.1.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpclient-4.2.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpcore-4.2.2.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\httpmime-4.2.3.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\jcl-over-slf4j-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\slf4j-api-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\slf4j-jdk14-1.6.4.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\wstx-asl-3.2.7.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\solrj\lib\zookeeper-3.4.5.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-continuation-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-deploy-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-http-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-io-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-jmx-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-security-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-server-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-servlet-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-util-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-webapp-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\jetty-xml-8.1.8.v20121106.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\lib\servlet-api-3.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\example-DIH\solr\db\lib\derby-10.9.1.0.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\example\example-DIH\solr\db\lib\hsqldb-1.8.0.10.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\build\core\classes\java;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\test-framework\lib\junit-4.10.jar;C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\test-framework\lib\randomizedtesting-runner-2.0.8.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-launcher.jar;C:\Users\JenkinsSlave\.ant\lib\ivy-2.3.0.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-antlr.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-bcel.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-bsf.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-log4j.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-oro.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-regexp.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-resolver.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-apache-xalan2.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-commons-logging.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-commons-net.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jai.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-javamail.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jdepend.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jmf.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-jsch.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-junit.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-junit4.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-netrexx.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-swing.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant-testutil.jar;C:\Users\JenkinsSlave\tools\hudson.tasks.Ant_AntInstallation\ANT_1.8.2\lib\ant.jar;C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\lib\tools.jar;C:\Users\JenkinsSlave\.ivy2\cache\com.carrotsearch.randomizedtesting\junit4-ant\jars\junit4-ant-2.0.8.jar
[junit4:junit4] 2> 308 T17 oaz.Environment.logEnv Client environment:java.library.path=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre\bin;C:\Windows\Sun\Java\bin;C:\Windows\system32;C:\Windows;C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Program Files (x86)\Subversion\bin;.
[junit4:junit4] 2> 309 T17 oaz.Environment.logEnv Client environment:java.io.tmpdir=.
[junit4:junit4] 2> 310 T17 oaz.Environment.logEnv Client environment:java.compiler=<NA>
[junit4:junit4] 2> 310 T17 oaz.Environment.logEnv Client environment:os.name=Windows 7
[junit4:junit4] 2> 311 T17 oaz.Environment.logEnv Client environment:os.arch=x86
[junit4:junit4] 2> 311 T17 oaz.Environment.logEnv Client environment:os.version=6.1
[junit4:junit4] 2> 311 T17 oaz.Environment.logEnv Client environment:user.name=JenkinsSlave
[junit4:junit4] 2> 312 T17 oaz.Environment.logEnv Client environment:user.home=C:\Users\JenkinsSlave
[junit4:junit4] 2> 312 T17 oaz.Environment.logEnv Client environment:user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 317 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@118463c
[junit4:junit4] 2> 390 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 400 T23 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 401 T23 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 586 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51325
[junit4:junit4] 2> 612 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51325
[junit4:junit4] 2> 624 T21 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 668 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10000 with negotiated timeout 10000 for client /127.0.0.1:51325
[junit4:junit4] 2> 668 T23 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10000, negotiated timeout = 10000
[junit4:junit4] 2> 677 T24 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@118463c name:ZooKeeperConnection Watcher:127.0.0.1:51322 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 678 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 682 T17 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 760 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10000
[junit4:junit4] 2> 763 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10000 closed
[junit4:junit4] 2> 764 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51325 which had sessionid 0x13d4d8d5ec10000
[junit4:junit4] 2> 765 T24 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 764 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1ac7f84
[junit4:junit4] 2> 768 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 769 T25 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 770 T25 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 771 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51328
[junit4:junit4] 2> 772 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51328
[junit4:junit4] 2> 774 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10001 with negotiated timeout 10000 for client /127.0.0.1:51328
[junit4:junit4] 2> 774 T25 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10001, negotiated timeout = 10000
[junit4:junit4] 2> 775 T26 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ac7f84 name:ZooKeeperConnection Watcher:127.0.0.1:51322/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 775 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 795 T17 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 807 T17 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 814 T17 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 819 T17 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 827 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 849 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 864 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 875 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 883 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 884 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 891 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 892 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 899 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 900 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 906 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 907 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 914 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 915 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 925 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 926 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 937 T17 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 937 T17 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 945 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10001
[junit4:junit4] 2> 947 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10001 closed
[junit4:junit4] 2> 947 T26 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 947 T19 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d4d8d5ec10001, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 951 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51328 which had sessionid 0x13d4d8d5ec10001
[junit4:junit4] 2> 1725 T17 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 1976 T17 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51329
[junit4:junit4] 2> 2024 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2026 T17 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2027 T17 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004
[junit4:junit4] 2> 2027 T17 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\solr.xml
[junit4:junit4] 2> 2028 T17 oasc.CoreContainer.<init> New CoreContainer 6086748
[junit4:junit4] 2> 2029 T17 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\'
[junit4:junit4] 2> 2030 T17 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\'
[junit4:junit4] 2> 2111 T17 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2111 T17 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2112 T17 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2112 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2112 T17 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2113 T17 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2114 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2115 T17 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2115 T17 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2156 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2745 T17 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 2785 T17 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:51322/solr
[junit4:junit4] 2> 2805 T17 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2806 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1e715fa
[junit4:junit4] 2> 2816 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2819 T37 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 2820 T37 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 2820 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51334
[junit4:junit4] 2> 2821 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51334
[junit4:junit4] 2> 2837 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10002 with negotiated timeout 20000 for client /127.0.0.1:51334
[junit4:junit4] 2> 2837 T37 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10002, negotiated timeout = 20000
[junit4:junit4] 2> 2838 T38 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e715fa name:ZooKeeperConnection Watcher:127.0.0.1:51322 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2839 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2842 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10002
[junit4:junit4] 2> 2845 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51334 which had sessionid 0x13d4d8d5ec10002
[junit4:junit4] 2> 2845 T38 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 2845 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10002 closed
[junit4:junit4] 2> 2852 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2870 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@11a5ae9
[junit4:junit4] 2> 2872 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2873 T39 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 2874 T39 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 2874 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51337
[junit4:junit4] 2> 2874 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51337
[junit4:junit4] 2> 2878 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10003 with negotiated timeout 20000 for client /127.0.0.1:51337
[junit4:junit4] 2> 2878 T39 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10003, negotiated timeout = 20000
[junit4:junit4] 2> 2879 T40 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11a5ae9 name:ZooKeeperConnection Watcher:127.0.0.1:51322/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2879 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2907 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2925 T17 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2932 T17 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51329__tl%2Fi
[junit4:junit4] 2> 2938 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:51329__tl%2Fi Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:51329__tl%2Fi
[junit4:junit4] 2> 2939 T17 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51329__tl%2Fi
[junit4:junit4] 2> 2949 T17 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2979 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4] 2> 2982 T17 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2992 T17 oasc.Overseer.start Overseer (id=89312837192712195-127.0.0.1:51329__tl%2Fi-n_0000000000) starting
[junit4:junit4] 2> 2994 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3012 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3014 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3024 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3027 T17 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 3046 T42 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 3056 T17 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 3062 T17 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 3084 T41 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 3130 T43 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\collection1
[junit4:junit4] 2> 3131 T43 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 3133 T43 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 3133 T43 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 3149 T43 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\collection1\'
[junit4:junit4] 2> 3154 T43 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 3156 T43 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004/collection1/lib/README' to classloader
[junit4:junit4] 2> 3280 T43 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 3373 T43 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 3375 T43 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 3437 T43 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 4361 T43 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 4380 T43 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 4384 T43 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 4434 T43 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4447 T43 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 4453 T43 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4454 T43 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 4457 T43 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 4457 T43 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 4461 T43 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 4461 T43 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 4462 T43 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1362805744004\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/control/data\
[junit4:junit4] 2> 4468 T43 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a73a8c
[junit4:junit4] 2> 4470 T43 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 4470 T43 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\control\data forceNew: false
[junit4:junit4] 2> 4470 T43 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/control/data\index/
[junit4:junit4] 2> 4471 T43 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 4472 T43 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\control\data\index forceNew: false
[junit4:junit4] 2> 4478 T43 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1341055 lockFactory=org.apache.lucene.store.NativeFSLockFactory@65a8d0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 4478 T43 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 4534 T43 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 4534 T43 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 4536 T43 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 4540 T43 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 4541 T43 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 4541 T43 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 4541 T43 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 4541 T43 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 4542 T43 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 4560 T43 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 4575 T43 oass.SolrIndexSearcher.<init> Opening Searcher@1afedcf main
[junit4:junit4] 2> 4583 T43 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\control\data\tlog
[junit4:junit4] 2> 4607 T43 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 4607 T43 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 4615 T44 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1afedcf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 4622 T43 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 4622 T43 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 4624 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x58 zxid:0x2a txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 6084 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6088 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:51329__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51329/_tl/i"}
[junit4:junit4] 2> 6088 T41 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 6126 T41 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6127 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x60 zxid:0x2d txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 6161 T40 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> 6617 T43 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 6617 T43 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51329/_tl/i collection:control_collection shard:shard1
[junit4:junit4] 2> 6634 T43 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 6650 T43 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 6669 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:delete cxid:0x7a zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4] 2> 6671 T43 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 6672 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x7b zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 6677 T43 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 6677 T43 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 6682 T43 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51329/_tl/i/collection1/
[junit4:junit4] 2> 6682 T43 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 6682 T43 oasc.SyncStrategy.syncToMe http://127.0.0.1:51329/_tl/i/collection1/ has no replicas
[junit4:junit4] 2> 6682 T43 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51329/_tl/i/collection1/
[junit4:junit4] 2> 6683 T43 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 6694 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10003 type:create cxid:0x85 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7659 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7705 T40 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> 7756 T43 oasc.ZkController.register We are http://127.0.0.1:51329/_tl/i/collection1/ and leader is http://127.0.0.1:51329/_tl/i/collection1/
[junit4:junit4] 2> 7764 T43 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51329/_tl/i
[junit4:junit4] 2> 7764 T43 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 7764 T43 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 7764 T43 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 7768 T43 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7776 T17 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 7777 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 7828 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 7844 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 7849 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@cb09c8
[junit4:junit4] 2> 7850 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 7851 T46 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 7852 T46 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 7852 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51340
[junit4:junit4] 2> 7854 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51340
[junit4:junit4] 2> 7857 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10004 with negotiated timeout 10000 for client /127.0.0.1:51340
[junit4:junit4] 2> 7857 T46 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10004, negotiated timeout = 10000
[junit4:junit4] 2> 7858 T47 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cb09c8 name:ZooKeeperConnection Watcher:127.0.0.1:51322/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 7858 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 7861 T17 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 7868 T17 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 8236 T17 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8239 T17 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51341
[junit4:junit4] 2> 8241 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8242 T17 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8243 T17 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924
[junit4:junit4] 2> 8243 T17 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\solr.xml
[junit4:junit4] 2> 8244 T17 oasc.CoreContainer.<init> New CoreContainer 26305948
[junit4:junit4] 2> 8244 T17 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\'
[junit4:junit4] 2> 8245 T17 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\'
[junit4:junit4] 2> 8297 T17 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8298 T17 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8298 T17 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8299 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8299 T17 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8300 T17 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8300 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8301 T17 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8301 T17 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8302 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8317 T17 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8344 T17 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:51322/solr
[junit4:junit4] 2> 8345 T17 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8346 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1f726d0
[junit4:junit4] 2> 8348 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8349 T57 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8351 T57 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 8351 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51346
[junit4:junit4] 2> 8351 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51346
[junit4:junit4] 2> 8363 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10005 with negotiated timeout 20000 for client /127.0.0.1:51346
[junit4:junit4] 2> 8363 T57 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10005, negotiated timeout = 20000
[junit4:junit4] 2> 8364 T58 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f726d0 name:ZooKeeperConnection Watcher:127.0.0.1:51322 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8364 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8367 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10005
[junit4:junit4] 2> 8369 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51346 which had sessionid 0x13d4d8d5ec10005
[junit4:junit4] 2> 8369 T58 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8369 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10005 closed
[junit4:junit4] 2> 8371 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8378 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@b2d46e
[junit4:junit4] 2> 8381 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8383 T59 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8384 T59 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 8385 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51349
[junit4:junit4] 2> 8385 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51349
[junit4:junit4] 2> 8389 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10006 with negotiated timeout 20000 for client /127.0.0.1:51349
[junit4:junit4] 2> 8390 T59 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10006, negotiated timeout = 20000
[junit4:junit4] 2> 8391 T60 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b2d46e name:ZooKeeperConnection Watcher:127.0.0.1:51322/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8391 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8394 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8398 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8406 T17 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9119 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9121 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:51329__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51329/_tl/i"}
[junit4:junit4] 2> 9135 T60 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> 9197 T40 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> 9198 T47 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> 9309 T17 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51341__tl%2Fi
[junit4:junit4] 2> 9310 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:delete cxid:0xd zxid:0x50 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:51341__tl%2Fi Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:51341__tl%2Fi
[junit4:junit4] 2> 9314 T17 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51341__tl%2Fi
[junit4:junit4] 2> 9323 T40 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> 9324 T47 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> 9327 T60 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 9328 T60 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> 9339 T40 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 9342 T47 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 9367 T61 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\collection1
[junit4:junit4] 2> 9368 T61 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 9370 T61 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 9371 T61 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 9377 T61 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\collection1\'
[junit4:junit4] 2> 9380 T61 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 9383 T61 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924/collection1/lib/README' to classloader
[junit4:junit4] 2> 9449 T61 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 9510 T61 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 9513 T61 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 9549 T61 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10337 T61 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10351 T61 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10354 T61 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10391 T61 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10398 T61 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10404 T61 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10407 T61 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10407 T61 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10407 T61 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10410 T61 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10410 T61 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10411 T61 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1362805750924\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty1\
[junit4:junit4] 2> 10411 T61 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a73a8c
[junit4:junit4] 2> 10412 T61 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10413 T61 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty1 forceNew: false
[junit4:junit4] 2> 10413 T61 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty1\index/
[junit4:junit4] 2> 10414 T61 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10414 T61 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty1\index forceNew: false
[junit4:junit4] 2> 10418 T61 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1937add lockFactory=org.apache.lucene.store.NativeFSLockFactory@1407ae8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10418 T61 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10422 T61 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10423 T61 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10424 T61 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10426 T61 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10428 T61 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10428 T61 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10428 T61 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10429 T61 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10429 T61 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10438 T61 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10445 T61 oass.SolrIndexSearcher.<init> Opening Searcher@d96b63 main
[junit4:junit4] 2> 10445 T61 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty1\tlog
[junit4:junit4] 2> 10446 T61 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10447 T61 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10458 T62 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@d96b63 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10461 T61 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10461 T61 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 10549 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10553 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51341__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51341/_tl/i"}
[junit4:junit4] 2> 10554 T41 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 10555 T41 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 10581 T60 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> 10582 T40 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> 10582 T47 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> 11360 T61 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 11360 T61 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51341/_tl/i collection:collection1 shard:shard1
[junit4:junit4] 2> 11361 T61 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 11379 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:delete cxid:0x4a zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4] 2> 11381 T61 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 11382 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:create cxid:0x4b zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11387 T61 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 11387 T61 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 11388 T61 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51341/_tl/i/collection1/
[junit4:junit4] 2> 11388 T61 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 11388 T61 oasc.SyncStrategy.syncToMe http://127.0.0.1:51341/_tl/i/collection1/ has no replicas
[junit4:junit4] 2> 11388 T61 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51341/_tl/i/collection1/
[junit4:junit4] 2> 11389 T61 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 11401 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10006 type:create cxid:0x55 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 11949 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11995 T60 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> 11995 T40 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> 11996 T47 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> 12042 T61 oasc.ZkController.register We are http://127.0.0.1:51341/_tl/i/collection1/ and leader is http://127.0.0.1:51341/_tl/i/collection1/
[junit4:junit4] 2> 12042 T61 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51341/_tl/i
[junit4:junit4] 2> 12043 T61 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 12043 T61 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 12043 T61 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12051 T61 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12055 T17 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 12056 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12057 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12383 T17 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 12386 T17 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51350
[junit4:junit4] 2> 12387 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 12387 T17 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 12387 T17 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131
[junit4:junit4] 2> 12388 T17 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\solr.xml
[junit4:junit4] 2> 12389 T17 oasc.CoreContainer.<init> New CoreContainer 5410452
[junit4:junit4] 2> 12389 T17 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\'
[junit4:junit4] 2> 12390 T17 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\'
[junit4:junit4] 2> 12439 T17 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 12439 T17 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 12440 T17 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 12440 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 12440 T17 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 12440 T17 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 12441 T17 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 12441 T17 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 12447 T17 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 12447 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 12464 T17 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 12483 T17 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:51322/solr
[junit4:junit4] 2> 12484 T17 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 12484 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@18e98bc
[junit4:junit4] 2> 12485 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12486 T73 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12487 T73 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 12488 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51355
[junit4:junit4] 2> 12488 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51355
[junit4:junit4] 2> 12499 T73 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10007, negotiated timeout = 20000
[junit4:junit4] 2> 12500 T74 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18e98bc name:ZooKeeperConnection Watcher:127.0.0.1:51322 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12500 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10007 with negotiated timeout 20000 for client /127.0.0.1:51355
[junit4:junit4] 2> 12500 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12509 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10007
[junit4:junit4] 2> 12511 T74 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 12511 T19 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d4d8d5ec10007, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 12511 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10007 closed
[junit4:junit4] 2> 12513 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 12515 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51355 which had sessionid 0x13d4d8d5ec10007
[junit4:junit4] 2> 12522 T17 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:51322/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1449c16
[junit4:junit4] 2> 12523 T17 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 12524 T75 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:51322. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 12525 T75 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:51322, initiating session
[junit4:junit4] 2> 12525 T19 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:51358
[junit4:junit4] 2> 12526 T19 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:51358
[junit4:junit4] 2> 12529 T21 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d4d8d5ec10008 with negotiated timeout 20000 for client /127.0.0.1:51358
[junit4:junit4] 2> 12529 T75 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:51322, sessionid = 0x13d4d8d5ec10008, negotiated timeout = 20000
[junit4:junit4] 2> 12530 T76 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1449c16 name:ZooKeeperConnection Watcher:127.0.0.1:51322/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 12530 T17 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 12531 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12534 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12540 T17 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13365 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13368 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51341__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51341/_tl/i"}
[junit4:junit4] 2> 13385 T60 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> 13386 T40 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> 13386 T76 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> 13387 T47 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> 13438 T17 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51350__tl%2Fi
[junit4:junit4] 2> 13441 T22 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d4d8d5ec10008 type:delete cxid:0xd zxid:0x74 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:51350__tl%2Fi Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:51350__tl%2Fi
[junit4:junit4] 2> 13445 T17 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51350__tl%2Fi
[junit4:junit4] 2> 13454 T40 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> 13456 T76 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> 13458 T60 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 13458 T60 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> 13460 T47 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> 13470 T40 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 13473 T76 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 13476 T47 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 13497 T77 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\collection1
[junit4:junit4] 2> 13498 T77 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 13499 T77 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 13499 T77 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 13502 T77 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\collection1\'
[junit4:junit4] 2> 13504 T77 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 13506 T77 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131/collection1/lib/README' to classloader
[junit4:junit4] 2> 13567 T77 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 13630 T77 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 13633 T77 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 13656 T77 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 14346 T77 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 14360 T77 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 14365 T77 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 14396 T77 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14403 T77 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 14410 T77 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14413 T77 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14413 T77 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14413 T77 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 14416 T77 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 14416 T77 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 14417 T77 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1362805755131\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty2\
[junit4:junit4] 2> 14417 T77 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a73a8c
[junit4:junit4] 2> 14420 T77 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 14421 T77 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2 forceNew: false
[junit4:junit4] 2> 14421 T77 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty2\index/
[junit4:junit4] 2> 14423 T77 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 14423 T77 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\index forceNew: false
[junit4:junit4] 2> 14428 T77 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1645af6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a62cb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 14428 T77 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 14433 T77 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 14434 T77 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 14435 T77 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 14437 T77 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 14438 T77 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 14439 T77 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 14439 T77 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 14440 T77 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 14441 T77 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 14460 T77 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 14467 T77 oass.SolrIndexSearcher.<init> Opening Searcher@807f8e main
[junit4:junit4] 2> 14469 T77 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\tlog
[junit4:junit4] 2> 14471 T77 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 14471 T77 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 14480 T78 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@807f8e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 14484 T77 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 14484 T77 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 14735 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14736 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51350__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51350/_tl/i"}
[junit4:junit4] 2> 14738 T41 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 14738 T41 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 14748 T60 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> 14749 T40 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> 14750 T76 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> 14752 T47 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> 15379 T77 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 15379 T77 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51350/_tl/i collection:collection1 shard:shard1
[junit4:junit4] 2> 15398 T77 oasc.ZkController.register We are http://127.0.0.1:51350/_tl/i/collection1/ and leader is http://127.0.0.1:51341/_tl/i/collection1/
[junit4:junit4] 2> 15398 T77 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51350/_tl/i
[junit4:junit4] 2> 15398 T77 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 15399 T77 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1 name=collection1 org.apache.solr.core.SolrCore@639f83 url=http://127.0.0.1:51350/_tl/i/collection1 node=127.0.0.1:51350__tl%2Fi C1_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:51350__tl%2Fi, base_url=http://127.0.0.1:51350/_tl/i}
[junit4:junit4] 2> 15412 T79 C1 P51350 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 15414 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 15414 T77 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 15415 T79 C1 P51350 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 15416 T79 C1 P51350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 15417 T17 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 15417 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 15418 T17 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15420 T79 C1 P51350 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 15430 T17 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16114 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16117 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[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:51350__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51350/_tl/i"}
[junit4:junit4] 2> 16131 T47 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> 16133 T60 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> 16134 T40 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> 16134 T76 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> 16168 T51 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=3&state=recovering&nodeName=127.0.0.1:51350__tl%252Fi&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=7
[junit4:junit4] 2> ASYNC NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@1ca1399 url=http://127.0.0.1:51329/_tl/i/collection1 node=127.0.0.1:51329__tl%2Fi C2_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:51329__tl%2Fi, base_url=http://127.0.0.1:51329/_tl/i, leader=true}
[junit4:junit4] 2> 16259 T35 C2 P51329 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1341055 lockFactory=org.apache.lucene.store.NativeFSLockFactory@65a8d0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16260 T35 C2 P51329 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16288 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10001 (1429005411876339712)]} 0 86
[junit4:junit4] 2> 16288 T35 C2 P51329 /update {wt=javabin&version=2} {add=[1 (1429005411875291136)]} 0 87
[junit4:junit4] 2> ASYNC NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@1946d47 url=http://127.0.0.1:51341/_tl/i/collection1 node=127.0.0.1:51341__tl%2Fi C3_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:51341__tl%2Fi, base_url=http://127.0.0.1:51341/_tl/i, leader=true}
[junit4:junit4] 2> 16323 T53 C3 P51341 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1937add lockFactory=org.apache.lucene.store.NativeFSLockFactory@1407ae8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16325 T53 C3 P51341 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> C1_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:51350__tl%2Fi, base_url=http://127.0.0.1:51350/_tl/i}
[junit4:junit4] 2> 16375 T72 C1 P51350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1645af6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a62cb),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 16376 T72 C1 P51350 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 16382 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1429005411943448576)]} 0 14
[junit4:junit4] 2> 16396 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10001 (1429005411942400000)]} 0 27
[junit4:junit4] 2> 16397 T54 C3 P51341 /update {wt=javabin&version=2} {add=[1 (1429005411943448576)]} 0 77
[junit4:junit4] 2> 16398 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10001 (1429005411942400000)]} 0 85
[junit4:junit4] 2> 16489 T34 C2 P51329 /update {wt=javabin&version=2} {add=[2 (1429005412114366464)]} 0 6
[junit4:junit4] 2> 16490 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10002 (1429005412119609344)]} 0 2
[junit4:junit4] 2> 16506 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1429005412124852224)]} 0 3
[junit4:junit4] 2> 16508 T55 C3 P51341 /update {wt=javabin&version=2} {add=[2 (1429005412124852224)]} 0 15
[junit4:junit4] 2> 16509 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10002 (1429005412126949376)]} 0 3
[junit4:junit4] 2> 16510 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10002 (1429005412126949376)]} 0 16
[junit4:junit4] 2> 16523 T31 C2 P51329 /update {wt=javabin&version=2} {add=[3 (1429005412153163776)]} 0 3
[junit4:junit4] 2> 16529 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10003 (1429005412158406656)]} 0 5
[junit4:junit4] 2> 16539 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1429005412159455232)]} 0 3
[junit4:junit4] 2> 16545 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10003 (1429005412169940992)]} 0 2
[junit4:junit4] 2> 16547 T51 C3 P51341 /update {wt=javabin&version=2} {add=[3 (1429005412159455232)]} 0 22
[junit4:junit4] 2> 16548 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10003 (1429005412169940992)]} 0 12
[junit4:junit4] 2> 16606 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10002 (-1429005412242292736)]} 0 3
[junit4:junit4] 2> 16606 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[2 (-1429005412241244160)]} 0 3
[junit4:junit4] 2> 16630 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[2 (-1429005412253827072)]} 0 2
[junit4:junit4] 2> 16635 T53 C3 P51341 /update {wt=javabin&version=2} {delete=[2 (-1429005412253827072)]} 0 21
[junit4:junit4] 2> 16644 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10002 (-1429005412251729920)]} 0 10
[junit4:junit4] 2> 16645 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[10002 (-1429005412251729920)]} 0 34
[junit4:junit4] 2> 16649 T34 C2 P51329 /update {wt=javabin&version=2} {add=[4 (1429005412284235776)]} 0 5
[junit4:junit4] 2> 16652 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10004 (1429005412289478656)]} 0 2
[junit4:junit4] 2> 16673 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1429005412294721536)]} 0 13
[junit4:junit4] 2> 16675 T55 C3 P51341 /update {wt=javabin&version=2} {add=[4 (1429005412294721536)]} 0 20
[junit4:junit4] 2> 16675 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10004 (1429005412296818688)]} 0 11
[junit4:junit4] 2> 16677 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10004 (1429005412296818688)]} 0 20
[junit4:junit4] 2> 16731 T31 C2 P51329 /update {wt=javabin&version=2} {add=[5 (1429005412372316160)]} 0 3
[junit4:junit4] 2> 16733 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10005 (1429005412372316161)]} 0 3
[junit4:junit4] 2> 16742 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1429005412378607616)]} 0 2
[junit4:junit4] 2> 16743 T52 C3 P51341 /update {wt=javabin&version=2} {add=[5 (1429005412378607616)]} 0 9
[junit4:junit4] 2> 16748 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10005 (1429005412380704768)]} 0 2
[junit4:junit4] 2> 16749 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10005 (1429005412380704768)]} 0 12
[junit4:junit4] 2> 16778 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[3 (-1429005412422647808)]} 0 3
[junit4:junit4] 2> 16781 T34 C2 P51329 /update {wt=javabin&version=2} {delete=[10003 (-1429005412426842112)]} 0 1
[junit4:junit4] 2> 16787 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[3 (-1429005412429987840)]} 0 1
[junit4:junit4] 2> 16788 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[3 (-1429005412429987840)]} 0 5
[junit4:junit4] 2> 16795 T33 C2 P51329 /update {wt=javabin&version=2} {add=[6 (1429005412439425024)]} 0 2
[junit4:junit4] 2> 16796 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10003 (-1429005412431036416)]} 0 4
[junit4:junit4] 2> 16800 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10003 (-1429005412431036416)]} 0 16
[junit4:junit4] 2> 16805 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10006 (1429005412449910784)]} 0 2
[junit4:junit4] 2> 16811 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1429005412444667904)]} 0 4
[junit4:junit4] 2> 16818 T51 C3 P51341 /update {wt=javabin&version=2} {add=[6 (1429005412444667904)]} 0 20
[junit4:junit4] 2> 16844 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10006 (1429005412460396544)]} 0 25
[junit4:junit4] 2> 16846 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10006 (1429005412460396544)]} 0 34
[junit4:junit4] 2> 16860 T31 C2 P51329 /update {wt=javabin&version=2} {add=[7 (1429005412507582464)]} 0 2
[junit4:junit4] 2> 16871 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1429005412513873920)]} 0 3
[junit4:junit4] 2> 16871 T52 C3 P51341 /update {wt=javabin&version=2} {add=[7 (1429005412513873920)]} 0 7
[junit4:junit4] 2> 16891 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10007 (1429005412536942592)]} 0 6
[junit4:junit4] 2> 16902 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10007 (1429005412546379776)]} 0 2
[junit4:junit4] 2> 16946 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10007 (1429005412546379776)]} 0 51
[junit4:junit4] 2> 16951 T35 C2 P51329 /update {wt=javabin&version=2} {add=[8 (1429005412603002880)]} 0 2
[junit4:junit4] 2> 16963 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1429005412611391488)]} 0 2
[junit4:junit4] 2> 16965 T54 C3 P51341 /update {wt=javabin&version=2} {add=[8 (1429005412611391488)]} 0 9
[junit4:junit4] 2> 16978 T34 C2 P51329 /update {wt=javabin&version=2} {delete=[4 (-1429005412633411584)]} 0 0
[junit4:junit4] 2> 16992 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[4 (-1429005412636557312)]} 0 2
[junit4:junit4] 2> 16992 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[4 (-1429005412636557312)]} 0 11
[junit4:junit4] 2> 16997 T33 C2 P51329 /update {wt=javabin&version=2} {add=[9 (1429005412652285952)]} 0 2
[junit4:junit4] 2> 17007 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1429005412656480256)]} 0 2
[junit4:junit4] 2> 17009 T51 C3 P51341 /update {wt=javabin&version=2} {add=[9 (1429005412656480256)]} 0 9
[junit4:junit4] 2> 17057 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10008 (1429005412715200512)]} 0 2
[junit4:junit4] 2> 17067 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10008 (1429005412720443392)]} 0 2
[junit4:junit4] 2> 17068 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10008 (1429005412720443392)]} 0 7
[junit4:junit4] 2> 17084 T31 C2 P51329 /update {wt=javabin&version=2} {delete=[10004 (-1429005412744560640)]} 0 0
[junit4:junit4] 2> 17092 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10004 (-1429005412748754944)]} 0 1
[junit4:junit4] 2> 17093 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[10004 (-1429005412748754944)]} 0 5
[junit4:junit4] 2> 17102 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10009 (1429005412762386432)]} 0 2
[junit4:junit4] 2> 17116 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10009 (1429005412767629312)]} 0 4
[junit4:junit4] 2> 17117 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10009 (1429005412767629312)]} 0 11
[junit4:junit4] 2> 17127 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10 (1429005412786503680)]} 0 6
[junit4:junit4] 2> 17139 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1429005412794892288)]} 0 3
[junit4:junit4] 2> 17141 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10 (1429005412794892288)]} 0 10
[junit4:junit4] 2> 17186 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10010 (1429005412849418240)]} 0 2
[junit4:junit4] 2> 17202 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10010 (1429005412857806848)]} 0 3
[junit4:junit4] 2> 17203 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10010 (1429005412857806848)]} 0 12
[junit4:junit4] 2> 17228 T36 C2 P51329 /update {wt=javabin&version=2} {delete=[5 (-1429005412895555584)]} 0 0
[junit4:junit4] 2> 17229 T17 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51350
[junit4:junit4] 2> 17229 T17 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=5410452
[junit4:junit4] 2> 17237 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[5 (-1429005412898701312)]} 0 0
[junit4:junit4] 2> 17239 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[5 (-1429005412898701312)]} 0 8
[junit4:junit4] 2> 17254 T31 C2 P51329 /update {wt=javabin&version=2} {add=[11 (1429005412918624256)]} 0 4
[junit4:junit4] 2> 17274 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1429005412929110016)]} 0 5
[junit4:junit4] 2> 17277 T53 C3 P51341 /update {wt=javabin&version=2} {add=[11 (1429005412929110016)]} 0 19
[junit4:junit4] 2> 17293 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10005 (-1429005412962664448)]} 0 1
[junit4:junit4] 2> 17303 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10005 (-1429005412971053056)]} 0 0
[junit4:junit4] 2> 17306 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[7 (-1429005412977344512)]} 0 1
[junit4:junit4] 2> 17306 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[10005 (-1429005412971053056)]} 0 8
[junit4:junit4] 2> 17317 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[7 (-1429005412983635968)]} 0 1
[junit4:junit4] 2> 17319 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10011 (1429005412985733120)]} 0 6
[junit4:junit4] 2> 17322 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[7 (-1429005412983635968)]} 0 10
[junit4:junit4] 2> 17332 T33 C2 P51329 /update {wt=javabin&version=2} {add=[12 (1429005413000413184)]} 0 5
[junit4:junit4] 2> 17348 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10011 (1429005412997267456)]} 0 13
[junit4:junit4] 2> 17353 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10011 (1429005412997267456)]} 0 28
[junit4:junit4] 2> 17355 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1429005413016141824)]} 0 2
[junit4:junit4] 2> 17356 T51 C3 P51341 /update {wt=javabin&version=2} {add=[12 (1429005413016141824)]} 0 17
[junit4:junit4] 2> 17366 T36 C2 P51329 /update {wt=javabin&version=2} {add=[13 (1429005413037113344)]} 0 4
[junit4:junit4] 2> 17377 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1429005413044453376)]} 0 1
[junit4:junit4] 2> 17378 T56 C3 P51341 /update {wt=javabin&version=2} {add=[13 (1429005413044453376)]} 0 8
[junit4:junit4] 2> 17383 T31 C2 P51329 /update {wt=javabin&version=2} {delete=[10007 (-1429005413057036288)]} 0 1
[junit4:junit4] 2> 17390 T71 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10007 (-1429005413062279168)]} 0 1
[junit4:junit4] 2> 17391 T53 C3 P51341 /update {wt=javabin&version=2} {delete=[10007 (-1429005413062279168)]} 0 4
[junit4:junit4] 2> 17398 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10012 (1429005413069619200)]} 0 4
[junit4:junit4] 2> 17414 T72 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10012 (1429005413079056384)]} 0 4
[junit4:junit4] 2> 17416 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10012 (1429005413079056384)]} 0 13
[junit4:junit4] 2> 17428 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10013 (1429005413100027904)]} 0 6
[junit4:junit4] 2> 17458 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10013 (1429005413110513664)]} 0 5
[junit4:junit4] 2> 17459 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10013 (1429005413110513664)]} 0 27
[junit4:junit4] 2> 17466 T34 C2 P51329 /update {wt=javabin&version=2} {add=[14 (1429005413141970944)]} 0 3
[junit4:junit4] 2> 17477 T69 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1429005413148262400)]} 0 2
[junit4:junit4] 2> 17478 T55 C3 P51341 /update {wt=javabin&version=2} {add=[14 (1429005413148262400)]} 0 9
[junit4:junit4] 2> 17516 T33 C2 P51329 /update {wt=javabin&version=2} {add=[15 (1429005413194399744)]} 0 4
[junit4:junit4] 2> 17535 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10014 (1429005413212225536)]} 0 6
[junit4:junit4] 2> 17539 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1429005413204885504)]} 0 6
[junit4:junit4] 2> 17542 T51 C3 P51341 /update {wt=javabin&version=2} {add=[15 (1429005413204885504)]} 0 20
[junit4:junit4] 2> 17553 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10014 (1429005413229002752)]} 0 2
[junit4:junit4] 2> 17554 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10014 (1429005413229002752)]} 0 9
[junit4:junit4] 2> 17563 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17565 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "shard":"shard1",
[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:51350__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51350/_tl/i"}
[junit4:junit4] 2> 17575 T60 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> 17576 T40 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> 17576 T76 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> 17576 T47 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> 17582 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[15 (-1429005413266751488)]} 0 3
[junit4:junit4] 2> 17587 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[15 (-1429005413270945792)]} 0 1
[junit4:junit4] 2> 17592 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10015 (1429005413275140096)]} 0 2
[junit4:junit4] 2> 17593 T34 C2 P51329 /update {wt=javabin&version=2} {add=[16 (1429005413275140097)]} 0 3
[junit4:junit4] 2> 17599 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10015 (1429005413281431552)]} 0 4
[junit4:junit4] 2> 17605 T55 C3 P51341 /update {wt=javabin&version=2} {add=[16 (1429005413282480128)]} 0 9
[junit4:junit4] 2> 17642 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10015 (-1429005413329666048)]} 0 0
[junit4:junit4] 2> 17648 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[10015 (-1429005413334908928)]} 0 1
[junit4:junit4] 2> 17654 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10016 (1429005413340151808)]} 0 3
[junit4:junit4] 2> 17660 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10016 (1429005413347491840)]} 0 2
[junit4:junit4] 2> 17668 T31 C2 P51329 /update {wt=javabin&version=2} {add=[17 (1429005413355880448)]} 0 1
[junit4:junit4] 2> 17674 T53 C3 P51341 /update {wt=javabin&version=2} {add=[17 (1429005413362171904)]} 0 2
[junit4:junit4] 2> 17704 T32 C2 P51329 /update {wt=javabin&version=2} {add=[18 (1429005413391532032)]} 0 3
[junit4:junit4] 2> 17708 T52 C3 P51341 /update {wt=javabin&version=2} {add=[18 (1429005413396774912)]} 0 2
[junit4:junit4] 2> 17724 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10017 (1429005413413552128)]} 0 3
[junit4:junit4] 2> 17729 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10017 (1429005413419843584)]} 0 2
[junit4:junit4] 2> 17763 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10018 (1429005413450252288)]} 0 6
[junit4:junit4] 2> 17765 T33 C2 P51329 /update {wt=javabin&version=2} {add=[19 (1429005413453398016)]} 0 5
[junit4:junit4] 2> 17769 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10018 (1429005413461786624)]} 0 2
[junit4:junit4] 2> 17771 T56 C3 P51341 /update {wt=javabin&version=2} {add=[19 (1429005413462835200)]} 0 3
[junit4:junit4] 2> 17819 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10019 (1429005413513166848)]} 0 2
[junit4:junit4] 2> 17825 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10019 (1429005413520506880)]} 0 2
[junit4:junit4] 2> 17838 T31 C2 P51329 /update {wt=javabin&version=2} {add=[20 (1429005413534138368)]} 0 2
[junit4:junit4] 2> 17843 T53 C3 P51341 /update {wt=javabin&version=2} {add=[20 (1429005413539381248)]} 0 2
[junit4:junit4] 2> 17893 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10020 (1429005413590761472)]} 0 2
[junit4:junit4] 2> 17899 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[16 (-1429005413599150080)]} 0 2
[junit4:junit4] 2> 17900 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10020 (1429005413597052928)]} 0 4
[junit4:junit4] 2> 17903 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[16 (-1429005413603344384)]} 0 1
[junit4:junit4] 2> 17907 T34 C2 P51329 /update {wt=javabin&version=2} {add=[21 (1429005413605441536)]} 0 2
[junit4:junit4] 2> 17912 T55 C3 P51341 /update {wt=javabin&version=2} {add=[21 (1429005413610684416)]} 0 2
[junit4:junit4] 2> 17925 T33 C2 P51329 /update {wt=javabin&version=2} {add=[22 (1429005413625364480)]} 0 2
[junit4:junit4] 2> 17932 T56 C3 P51341 /update {wt=javabin&version=2} {add=[22 (1429005413630607360)]} 0 3
[junit4:junit4] 2> 17953 T36 C2 P51329 /update {wt=javabin&version=2} {delete=[10016 (-1429005413655773184)]} 0 0
[junit4:junit4] 2> 17957 T53 C3 P51341 /update {wt=javabin&version=2} {delete=[10016 (-1429005413659967488)]} 0 1
[junit4:junit4] 2> 17962 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10021 (1429005413664161792)]} 0 2
[junit4:junit4] 2> 17968 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10021 (1429005413669404672)]} 0 3
[junit4:junit4] 2> 17984 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10022 (1429005413686181888)]} 0 3
[junit4:junit4] 2> 18000 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10022 (1429005413701910528)]} 0 3
[junit4:junit4] 2> 18017 T34 C2 P51329 /update {wt=javabin&version=2} {add=[23 (1429005413722882048)]} 0 1
[junit4:junit4] 2> 18023 T55 C3 P51341 /update {wt=javabin&version=2} {add=[23 (1429005413727076352)]} 0 3
[junit4:junit4] 2> 18076 T33 C2 P51329 /update {wt=javabin&version=2} {add=[24 (1429005413781602304)]} 0 4
[junit4:junit4] 2> 18085 T51 C3 P51341 /update {wt=javabin&version=2} {add=[24 (1429005413792088064)]} 0 3
[junit4:junit4] 2> 18091 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10023 (1429005413795233792)]} 0 5
[junit4:junit4] 2> 18100 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10023 (1429005413806768128)]} 0 4
[junit4:junit4] 2> C1_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:51350__tl%2Fi, base_url=http://127.0.0.1:51350/_tl/i}
[junit4:junit4] 2> 18145 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51341/_tl/i/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 18156 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10024 (1429005413862342656)]} 0 6
[junit4:junit4] 2> 18162 T79 C1 P51350 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 18166 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10024 (1429005413875974144)]} 0 4
[junit4:junit4] 2> 18184 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[17 (-1429005413897994240)]} 0 1
[junit4:junit4] 2> 18192 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[17 (-1429005413906382848)]} 0 2
[junit4:junit4] 2> 18201 T79 C1 P51350 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:51350/_tl/i START replicas=[http://127.0.0.1:51341/_tl/i/collection1/] nUpdates=100
[junit4:junit4] 2> 18221 T35 C2 P51329 /update {wt=javabin&version=2} {add=[25 (1429005413934694400)]} 0 2
[junit4:junit4] 2> 18228 T79 C1 P51350 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 18229 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 18229 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 18229 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 18230 T79 C1 P51350 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\tlog\tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 18230 T79 C1 P51350 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51341/_tl/i/collection1/. core=collection1
[junit4:junit4] 2> 18231 T79 C1 P51350 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 18232 T54 C3 P51341 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 18236 T54 C3 P51341 /update {wt=javabin&version=2} {add=[25 (1429005413950423040)]} 0 2
[junit4:junit4] 2> 18245 T51 C3 P51341 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 18254 T34 C2 P51329 /update {wt=javabin&version=2} {delete=[10017 (-1429005413971394560)]} 0 1
[junit4:junit4] 2> 18260 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[10017 (-1429005413975588864)]} 0 3
[junit4:junit4] 2> 18264 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10025 (1429005413979783168)]} 0 2
[junit4:junit4] 2> 18273 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10025 (1429005413986074624)]} 0 6
[junit4:junit4] 2> 18301 T51 C3 P51341 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1937add lockFactory=org.apache.lucene.store.NativeFSLockFactory@1407ae8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1937add lockFactory=org.apache.lucene.store.NativeFSLockFactory@1407ae8),segFN=segments_2,generation=2,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 18302 T51 C3 P51341 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 18308 T31 C2 P51329 /update {wt=javabin&version=2} {add=[26 (1429005414026969088)]} 0 2
[junit4:junit4] 2> 18332 T52 C3 P51341 /update {wt=javabin&version=2} {add=[26 (1429005414050037760)]} 0 3
[junit4:junit4] 2> 18353 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[18 (-1429005414075203584)]} 0 0
[junit4:junit4] 2> 18354 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10026 (1429005414067863552)]} 0 9
[junit4:junit4] 2> 18359 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[18 (-1429005414081495040)]} 0 1
[junit4:junit4] 2> 18361 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10026 (1429005414080446464)]} 0 5
[junit4:junit4] 2> 18366 T34 C2 P51329 /update {wt=javabin&version=2} {add=[27 (1429005414086737920)]} 0 2
[junit4:junit4] 2> 18370 T51 C3 P51341 oass.SolrIndexSearcher.<init> Opening Searcher@b83bce realtime
[junit4:junit4] 2> 18371 T51 C3 P51341 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 18371 T51 C3 P51341 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 127
[junit4:junit4] 2> 18380 T53 C3 P51341 /update {wt=javabin&version=2} {add=[27 (1429005414093029376)]} 0 11
[junit4:junit4] 2> 18389 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10018 (-1429005414112952320)]} 0 2
[junit4:junit4] 2> 18392 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[10018 (-1429005414116098048)]} 0 1
[junit4:junit4] 2> 18396 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10027 (1429005414120292352)]} 0 0
[junit4:junit4] 2> 18403 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10027 (1429005414124486656)]} 0 3
[junit4:junit4] 2> 18432 T79 C1 P51350 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 18432 T79 C1 P51350 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 18446 T79 C1 P51350 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 18500 T56 C3 P51341 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 18500 T56 C3 P51341 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=52
[junit4:junit4] 2> 18503 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 18503 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 18503 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 18505 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10019 (-1429005414234587136)]} 0 1
[junit4:junit4] 2> 18517 T54 C3 P51341 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=10
[junit4:junit4] 2> 18518 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 14
[junit4:junit4] 2> 18519 T79 C1 P51350 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\index.20130309050921575 forceNew: false
[junit4:junit4] 2> 18519 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae) fullCopy=true
[junit4:junit4] 2> 18524 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10019 (-1429005414254510080)]} 0 0
[junit4:junit4] 2> 18535 T53 C3 P51341 REQ /replication {file=_0_Lucene40_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=5
[junit4:junit4] 2> 18551 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10028 (1429005414280724480)]} 0 2
[junit4:junit4] 2> 18553 T52 C3 P51341 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 18558 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10028 (1429005414288064512)]} 0 2
[junit4:junit4] 2> 18560 T55 C3 P51341 REQ /replication {file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18564 T54 C3 P51341 REQ /replication {file=_0_dv.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18574 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[10020 (-1429005414306938880)]} 0 1
[junit4:junit4] 2> 18576 T51 C3 P51341 REQ /replication {file=_0_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18579 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[19 (-1429005414312181760)]} 0 4
[junit4:junit4] 2> 18581 T53 C3 P51341 REQ /replication {file=_0_Lucene40_0.prx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18585 T53 C3 P51341 /update {wt=javabin&version=2} {delete=[19 (-1429005414318473216)]} 0 1
[junit4:junit4] 2> 18587 T53 C3 P51341 REQ /replication {file=_0_Lucene40_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18593 T34 C2 P51329 /update {wt=javabin&version=2} {add=[28 (1429005414324764672)]} 0 2
[junit4:junit4] 2> 18596 T52 C3 P51341 REQ /replication {file=_0_Lucene40_0.frq&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 18610 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10020 (-1429005414344687616)]} 0 1
[junit4:junit4] 2> 18613 T55 C3 P51341 /update {wt=javabin&version=2} {add=[28 (1429005414346784768)]} 0 1
[junit4:junit4] 2> 18622 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10029 (1429005414356221952)]} 0 1
[junit4:junit4] 2> 18624 T53 C3 P51341 REQ /replication {file=_0_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18630 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10029 (1429005414364610560)]} 0 1
[junit4:junit4] 2> 18632 T55 C3 P51341 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18636 T56 C3 P51341 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18640 T54 C3 P51341 REQ /replication {file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18644 T51 C3 P51341 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18654 T53 C3 P51341 REQ /replication {file=_0_dv.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 18659 T79 C1 P51350 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 18660 T79 C1 P51350 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130309050921575
[junit4:junit4] 2> 18667 T79 C1 P51350 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 18667 T79 C1 P51350 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 18667 T79 C1 P51350 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 18673 T79 C1 P51350 oasc.SolrCore.getNewIndexDir New index directory detected: old=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty2\index/ new=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065/jetty2\index.20130309050921575
[junit4:junit4] 2> 18678 T79 C1 P51350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae),segFN=segments_2,generation=2,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 18678 T79 C1 P51350 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> 18678 T79 C1 P51350 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 18681 T79 C1 P51350 oass.SolrIndexSearcher.<init> Opening Searcher@1b52472 main
[junit4:junit4] 2> 18682 T78 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b52472 main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C49/15)}
[junit4:junit4] 2> 18683 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[20 (-1429005414421233664)]} 0 1
[junit4:junit4] 2> 18684 T79 C1 P51350 oash.SnapPuller$2.preClose removing old index files MockDirWrapper(org.apache.lucene.store.RAMDirectory@1645af6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a62cb)
[junit4:junit4] 2> 18684 T79 C1 P51350 oasc.CachingDirectoryFactory.closeDirectory Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\index
[junit4:junit4] 2> 18684 T79 C1 P51350 oash.SnapPuller$2.postClose removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@1645af6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12a62cb)
[junit4:junit4] 2> 18689 T79 C1 P51350 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 18690 T87 C1 P51350 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1362805743065\jetty2\tlog\tlog.0000000000000000000 refcount=2} active=true starting pos=3228
[junit4:junit4] 2> 18692 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[20 (-1429005414430670848)]} 0 0
[junit4:junit4] 2> 18694 T87 C1 P51350 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 18698 T87 C1 P51350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae),segFN=segments_2,generation=2,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, segments_2, _0.fdx, _0.si, _0.fdt, _0_dv.cfe]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae),segFN=segments_3,generation=3,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0.fdx, _0.si, _0.fdt, segments_3, _0_dv.cfe]
[junit4:junit4] 2> 18698 T36 C2 P51329 /update {wt=javabin&version=2} {add=[29 (1429005414432768000)]} 0 4
[junit4:junit4] 2> 18699 T87 C1 P51350 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0.fdx, _0.si, _0.fdt, segments_3, _0_dv.cfe]
[junit4:junit4] 2> 18702 T87 C1 P51350 oass.SolrIndexSearcher.<init> Opening Searcher@b5e69c main
[junit4:junit4] 2> 18703 T87 C1 P51350 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 18704 T78 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b5e69c main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C49/15)}
[junit4:junit4] 2> 18704 T52 C3 P51341 /update {wt=javabin&version=2} {add=[29 (1429005414442205184)]} 0 1
[junit4:junit4] 2> 18705 T87 C1 P51350 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=3228}
[junit4:junit4] 2> 18705 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 18706 T79 C1 P51350 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 18706 T79 C1 P51350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 18710 T79 C1 P51350 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 18777 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10030 (1429005414517702656)]} 0 3
[junit4:junit4] 2> 18786 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10030 (1429005414526091264)]} 0 4
[junit4:junit4] 2> 18802 T34 C2 P51329 /update {wt=javabin&version=2} {add=[30 (1429005414542868480)]} 0 4
[junit4:junit4] 2> 18811 T51 C3 P51341 /update {wt=javabin&version=2} {add=[30 (1429005414552305664)]} 0 4
[junit4:junit4] 2> 18888 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10031 (1429005414633046016)]} 0 4
[junit4:junit4] 2> 18897 T53 C3 P51341 /update {wt=javabin&version=2} {add=[10031 (1429005414642483200)]} 0 4
[junit4:junit4] 2> 18912 T32 C2 P51329 /update {wt=javabin&version=2} {add=[31 (1429005414658211840)]} 0 3
[junit4:junit4] 2> 18922 T55 C3 P51341 /update {wt=javabin&version=2} {add=[31 (1429005414667649024)]} 0 5
[junit4:junit4] 2> 18946 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10032 (1429005414692814848)]} 0 4
[junit4:junit4] 2> 18955 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10032 (1429005414704349184)]} 0 3
[junit4:junit4] 2> 18970 T35 C2 P51329 /update {wt=javabin&version=2} {add=[32 (1429005414719029248)]} 0 3
[junit4:junit4] 2> 18976 T54 C3 P51341 /update {wt=javabin&version=2} {add=[32 (1429005414726369280)]} 0 3
[junit4:junit4] 2> 19008 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10022 (-1429005414762020864)]} 0 1
[junit4:junit4] 2> 19012 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[10022 (-1429005414766215168)]} 0 0
[junit4:junit4] 2> 19017 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10033 (1429005414770409472)]} 0 2
[junit4:junit4] 2> 19027 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10033 (1429005414776700928)]} 0 6
[junit4:junit4] 2> 19028 T31 C2 P51329 /update {wt=javabin&version=2} {delete=[22 (-1429005414781943808)]} 0 1
[junit4:junit4] 2> 19034 T53 C3 P51341 /update {wt=javabin&version=2} {delete=[22 (-1429005414789283840)]} 0 1
[junit4:junit4] 2> 19047 T32 C2 P51329 /update {wt=javabin&version=2} {add=[33 (1429005414793478144)]} 0 10
[junit4:junit4] 2> 19067 T55 C3 P51341 /update {wt=javabin&version=2} {add=[33 (1429005414822838272)]} 0 14
[junit4:junit4] 2> 19072 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19074 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:51350__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51350/_tl/i"}
[junit4:junit4] 2> 19084 T60 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> 19085 T40 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> 19085 T76 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> 19086 T47 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> 19121 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10034 (1429005414879461376)]} 0 2
[junit4:junit4] 2> C1_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:51350__tl%2Fi, base_url=http://127.0.0.1:51350/_tl/i}
[junit4:junit4] 2> 19136 T68 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10034 (1429005414884704256)]} 0 7
[junit4:junit4] 2> 19138 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10034 (1429005414884704256)]} 0 14
[junit4:junit4] 2> 19163 T35 C2 P51329 /update {wt=javabin&version=2} {add=[34 (1429005414922452992)]} 0 3
[junit4:junit4] 2> 19189 T70 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1429005414931890176)]} 0 7
[junit4:junit4] 2> 19192 T54 C3 P51341 /update {wt=javabin&version=2} {add=[34 (1429005414931890176)]} 0 23
[junit4:junit4] 2> 19208 T17 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 19208 T17 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19213 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10035 (1429005414975930368)]} 0 1
[junit4:junit4] 2> 19227 T17 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@639f83
[junit4:junit4] 2> 19245 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10035 (1429005414984318976)]} 0 2
[junit4:junit4] 2> 19246 T67 C1 P51350 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@639f83
[junit4:junit4] 2> 19253 T67 C1 P51350 oasc.SolrException.log SEVERE org.apache.solr.common.SolrException: Failed to unregister info bean: highlight
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:178)
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.clear(JmxMonitoredMap.java:116)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.close(SolrCore.java:959)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:372)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[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> Caused by: javax.management.InstanceNotFoundException: solr/collection1:type=highlight,id=highlight
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1095)
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:427)
[junit4:junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
[junit4:junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:537)
[junit4:junit4] 2> at org.apache.solr.core.JmxMonitoredMap.unregister(JmxMonitoredMap.java:175)
[junit4:junit4] 2> ... 29 more
[junit4:junit4] 2>
[junit4:junit4] 2> 19254 T67 C1 P51350 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=3,adds=3,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=32,cumulative_deletesById=10,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 19256 T67 C1 P51350 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 19256 T67 C1 P51350 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 19257 T67 C1 P51350 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 19257 T17 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=3,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=32,cumulative_deletesById=10,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 19262 T31 C2 P51329 /update {wt=javabin&version=2} {add=[35 (1429005415027310592)]} 0 2
[junit4:junit4] 2> 19263 T67 C1 P51350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae),segFN=segments_3,generation=3,filenames=[_0_Lucene40_0.tim, _0.fnm, _0_1.del, _0_dv.cfs, _0_nrm.cfs, _0_Lucene40_0.prx, _0_Lucene40_0.tip, _0_Lucene40_0.frq, _0_nrm.cfe, _0.fdx, _0.si, _0.fdt, segments_3, _0_dv.cfe]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae),segFN=segments_4,generation=4,filenames=[_2.si, _0_dv.cfs, _0_Lucene40_0.prx, _2_dv.cfs, _2_Lucene40_0.tip, _2_nrm.cfe, _0_Lucene40_0.frq, _2_Lucene40_0.tim, _0.si, _2_nrm.cfs, _0_Lucene40_0.tim, _0.fnm, _0_1.del, _2.fdt, _0_nrm.cfs, _2.fdx, _0_Lucene40_0.tip, _2.fnm, _2_Lucene40_0.frq, _2_Lucene40_0.prx, _0_nrm.cfe, _0.fdx, _0.fdt, _2_dv.cfe, segments_4, _0_dv.cfe]
[junit4:junit4] 2> 19264 T67 C1 P51350 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_2.si, _0_dv.cfs, _0_Lucene40_0.prx, _2_dv.cfs, _2_Lucene40_0.tip, _2_nrm.cfe, _0_Lucene40_0.frq, _2_Lucene40_0.tim, _0.si, _2_nrm.cfs, _0_Lucene40_0.tim, _0.fnm, _0_1.del, _2.fdt, _0_nrm.cfs, _2.fdx, _0_Lucene40_0.tip, _2.fnm, _2_Lucene40_0.frq, _2_Lucene40_0.prx, _0_nrm.cfe, _0.fdx, _0.fdt, _2_dv.cfe, segments_4, _0_dv.cfe]
[junit4:junit4] 2> 19269 T67 C1 P51350 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 19269 T17 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 19271 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10035 (1429005414984318976)]} 0 52
[junit4:junit4] 2> 19274 T22 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d4d8d5ec10008
[junit4:junit4] 2> 19278 T67 C1 P51350 oass.SolrIndexSearcher.<init> Opening Searcher@f7867f main
[junit4:junit4] 2> 19278 T40 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> 19279 T76 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> 19279 T19 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:51358 which had sessionid 0x13d4d8d5ec10008
[junit4:junit4] 2> 19282 T47 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> 19282 T17 oaz.ZooKeeper.close Session: 0x13d4d8d5ec10008 closed
[junit4:junit4] 2> 19283 T60 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 19283 T60 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> 19284 T67 C1 P51350 /update {distrib.from=http://127.0.0.1:51341/_tl/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {} 0 14
[junit4:junit4] 2> 19285 T76 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 19285 T76 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 19285 T76 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 19285 T67 C1 P51350 oasc.SolrException.log SEVERE java.lang.RuntimeException: SolrCoreState already closed
[junit4:junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:84)
[junit4:junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:153)
[junit4:junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:69)
[junit4:junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processAdd(UpdateRequestProcessor.java:51)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalAdd(DistributedUpdateProcessor.java:451)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:587)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:346)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:100)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processUpdate(XMLLoader.java:246)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:173)
[junit4:junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:92)
[junit4:junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
[junit4:junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1800)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:637)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:343)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[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>
[junit4:junit4] 2> 19291 T47 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 19293 T67 C1 P51350 oasc.SolrException.log SEVERE null:java.lang.RuntimeException: SolrCoreState already closed
[junit4:junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:84)
[junit4:junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.addDoc(DirectUpdateHandler2.java:153)
[junit4:junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processAdd(RunUpdateProcessorFactory.java:69)
[junit4:junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processAdd(UpdateRequestProcessor.java:51)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalAdd(DistributedUpdateProcessor.java:451)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionAdd(DistributedUpdateProcessor.java:587)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processAdd(DistributedUpdateProcessor.java:346)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processAdd(LogUpdateProcessorFactory.java:100)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.processUpdate(XMLLoader.java:246)
[junit4:junit4] 2> at org.apache.solr.handler.loader.XMLLoader.load(XMLLoader.java:173)
[junit4:junit4] 2> at org.apache.solr.handler.UpdateRequestHandler$1.load(UpdateRequestHandler.java:92)
[junit4:junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:74)
[junit4:junit4] 2> at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
[junit4:junit4] 2> at org.apache.solr.core.SolrCore.execute(SolrCore.java:1800)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:637)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:343)
[junit4:junit4] 2> at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1307)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:453)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:275)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1074)
[junit4:junit4] 2> at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:382)
[junit4:junit4] 2> at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1006)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
[junit4:junit4] 2> at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
[junit4:junit4] 2> at org.eclipse.jetty.server.Server.handle(Server.java:365)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:485)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection.content(AbstractHttpConnection.java:937)
[junit4:junit4] 2> at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.content(AbstractHttpConnection.java:998)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:948)
[junit4:junit4] 2> at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:240)
[junit4:junit4] 2> at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
[junit4:junit4] 2> at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
[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>
[junit4:junit4] 2> 19294 T67 C1 P51350 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@639f83
[junit4:junit4] 2> 19294 T67 C1 P51350 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=3,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=32,cumulative_deletesById=10,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 19295 T67 C1 P51350 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 19296 T40 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 19303 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10025 (-1429005415071350784)]} 0 0
[junit4:junit4] 2> 19311 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10025 (-1429005415079739392)]} 0 0
[junit4:junit4] 2> 19312 T53 C3 P51341 oasc.SolrException.log SEVERE shard update error StdNode: http://127.0.0.1:51350/_tl/i/collection1/:org.apache.solr.common.SolrException: Server at http://127.0.0.1:51350/_tl/i/collection1 returned non ok status:500, message:Server Error
[junit4:junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:373)
[junit4:junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] 2> at org.apache.solr.update.SolrCmdDistributor$1.call(SolrCmdDistributor.java:332)
[junit4:junit4] 2> at org.apache.solr.update.SolrCmdDistributor$1.call(SolrCmdDistributor.java:306)
[junit4:junit4] 2> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4] 2> at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 19317 T53 C3 P51341 oasup.DistributedUpdateProcessor.doFinish try and ask http://127.0.0.1:51350/_tl/i to recover
[junit4:junit4] 2> 19317 T53 C3 P51341 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19332 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10036 (1429005415100710912)]} 0 2
[junit4:junit4] 2> 19343 T17 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/_tl/i,null}
[junit4:junit4] 2> 19352 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10036 (1429005415114342400)]} 0 8
[junit4:junit4] 2> 19375 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10037 (1429005415144751104)]} 0 3
[junit4:junit4] 2> 19384 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10037 (1429005415155236864)]} 0 2
[junit4:junit4] 2> 19453 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10038 (1429005415225491456)]} 0 4
[junit4:junit4] 2> 19462 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10038 (1429005415234928640)]} 0 4
[junit4:junit4] 2> 19492 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10028 (-1429005415268483072)]} 0 1
[junit4:junit4] 2> 19498 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10028 (-1429005415275823104)]} 0 1
[junit4:junit4] 2> 19507 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10039 (1429005415282114560)]} 0 4
[junit4:junit4] 2> 19516 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10039 (1429005415290503168)]} 0 4
[junit4:junit4] 2> 19608 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10030 (-1429005415390117888)]} 0 1
[junit4:junit4] 2> 19614 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[10030 (-1429005415396409344)]} 0 1
[junit4:junit4] 2> 19622 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10040 (1429005415402700800)]} 0 4
[junit4:junit4] 2> 19630 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10040 (1429005415412137984)]} 0 3
[junit4:junit4] 2> 19687 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10041 (1429005415470858240)]} 0 4
[junit4:junit4] 2> 19695 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10041 (1429005415479246848)]} 0 4
[junit4:junit4] 2> 19769 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10031 (-1429005415559987200)]} 0 1
[junit4:junit4] 2> 19776 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10031 (-1429005415566278656)]} 0 1
[junit4:junit4] 2> 19782 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10042 (1429005415572570112)]} 0 2
[junit4:junit4] 2> 19792 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10042 (1429005415580958720)]} 0 4
[junit4:junit4] 2> 19832 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10032 (-1429005415624998912)]} 0 1
[junit4:junit4] 2> 19837 T52 C3 P51341 /update {wt=javabin&version=2} {delete=[10032 (-1429005415631290368)]} 0 0
[junit4:junit4] 2> 19846 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10043 (1429005415638630400)]} 0 3
[junit4:junit4] 2> 19855 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10043 (1429005415647019008)]} 0 4
[junit4:junit4] 2> 19951 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[10036 (-1429005415750828032)]} 0 1
[junit4:junit4] 2> 19957 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10036 (-1429005415756070912)]} 0 1
[junit4:junit4] 2> 19965 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10044 (1429005415762362368)]} 0 4
[junit4:junit4] 2> 19973 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10044 (1429005415770750976)]} 0 3
[junit4:junit4] 2> 20009 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10045 (1429005415808499712)]} 0 3
[junit4:junit4] 2> 20016 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10045 (1429005415817936896)]} 0 2
[junit4:junit4] 2> 20049 T32 C2 P51329 /update {wt=javabin&version=2} {delete=[10037 (-1429005415853588480)]} 0 1
[junit4:junit4] 2> 20052 T56 C3 P51341 /update {wt=javabin&version=2} {delete=[10037 (-1429005415856734208)]} 0 0
[junit4:junit4] 2> 20057 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10046 (1429005415860928512)]} 0 2
[junit4:junit4] 2> 20062 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10046 (1429005415866171392)]} 0 2
[junit4:junit4] 2> 20142 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[10038 (-1429005415950057472)]} 0 1
[junit4:junit4] 2> 20148 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10038 (-1429005415956348928)]} 0 1
[junit4:junit4] 2> 20158 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10047 (1429005415963688960)]} 0 5
[junit4:junit4] 2> 20166 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10047 (1429005415973126144)]} 0 4
[junit4:junit4] 2> 20244 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10048 (1429005416054915072)]} 0 4
[junit4:junit4] 2> 20251 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10048 (1429005416063303680)]} 0 3
[junit4:junit4] 2> 20309 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10049 (1429005416123072512)]} 0 3
[junit4:junit4] 2> 20317 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10049 (1429005416132509696)]} 0 3
[junit4:junit4] 2> 20353 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10050 (1429005416169209856)]} 0 4
[junit4:junit4] 2> 20361 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10050 (1429005416178647040)]} 0 3
[junit4:junit4] 2> 20421 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10051 (1429005416240513024)]} 0 4
[junit4:junit4] 2> 20428 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10051 (1429005416248901632)]} 0 2
[junit4:junit4] 2> 20521 T34 C2 P51329 /update {wt=javabin&version=2} {delete=[10040 (-1429005416347467776)]} 0 1
[junit4:junit4] 2> 20527 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[10040 (-1429005416353759232)]} 0 1
[junit4:junit4] 2> 20535 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10052 (1429005416361099264)]} 0 3
[junit4:junit4] 2> 20558 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10052 (1429005416369487872)]} 0 17
[junit4:junit4] 2> 20567 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20569 T41 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[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:51350__tl%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51350/_tl/i"}
[junit4:junit4] 2> 20585 T60 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> 20585 T40 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> 20586 T47 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> 20587 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10053 (1429005416413528064)]} 0 4
[junit4:junit4] 2> 20596 T51 C3 P51341 /update {wt=javabin&version=2} {add=[10053 (1429005416425062400)]} 0 3
[junit4:junit4] 2> 20649 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10054 (1429005416479588352)]} 0 4
[junit4:junit4] 2> 20657 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10054 (1429005416487976960)]} 0 4
[junit4:junit4] 2> 20743 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10055 (1429005416578154496)]} 0 4
[junit4:junit4] 2> 20751 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10055 (1429005416586543104)]} 0 4
[junit4:junit4] 2> 20761 T36 C2 P51329 /update {wt=javabin&version=2} {delete=[10043 (-1429005416600174592)]} 0 0
[junit4:junit4] 2> 20768 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[10043 (-1429005416606466048)]} 0 1
[junit4:junit4] 2> 20776 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10056 (1429005416612757504)]} 0 4
[junit4:junit4] 2> 20783 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10056 (1429005416621146112)]} 0 3
[junit4:junit4] 2> 20882 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10046 (-1429005416727052288)]} 0 1
[junit4:junit4] 2> 20887 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10046 (-1429005416732295168)]} 0 0
[junit4:junit4] 2> 20894 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10057 (1429005416738586624)]} 0 1
[junit4:junit4] 2> 20898 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10057 (1429005416741732352)]} 0 1
[junit4:junit4] 2> 20933 T35 C2 P51329 /update {wt=javabin&version=2} {delete=[10049 (-1429005416780529664)]} 0 1
[junit4:junit4] 2> 20937 T54 C3 P51341 /update {wt=javabin&version=2} {delete=[10049 (-1429005416784723968)]} 0 1
[junit4:junit4] 2> 20944 T36 C2 P51329 /update {wt=javabin&version=2} {add=[10058 (1429005416788918272)]} 0 4
[junit4:junit4] 2> 20952 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10058 (1429005416798355456)]} 0 3
[junit4:junit4] 2> 21016 T34 C2 P51329 /update {wt=javabin&version=2} {delete=[10050 (-1429005416867561472)]} 0 0
[junit4:junit4] 2> 21020 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10050 (-1429005416870707200)]} 0 1
[junit4:junit4] 2> 21025 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10059 (1429005416874901504)]} 0 2
[junit4:junit4] 2> 21029 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10059 (1429005416880144384)]} 0 1
[junit4:junit4] 2> 21058 T33 C2 P51329 /update {wt=javabin&version=2} {delete=[10054 (-1429005416910553088)]} 0 1
[junit4:junit4] 2> 21062 T55 C3 P51341 /update {wt=javabin&version=2} {delete=[10054 (-1429005416915795968)]} 0 1
[junit4:junit4] 2> 21067 T32 C2 P51329 /update {wt=javabin&version=2} {add=[10060 (1429005416919990272)]} 0 2
[junit4:junit4] 2> 21072 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10060 (1429005416925233152)]} 0 2
[junit4:junit4] 2> 21140 T35 C2 P51329 /update {wt=javabin&version=2} {add=[10061 (1429005416994439168)]} 0 4
[junit4:junit4] 2> 21148 T56 C3 P51341 /update {wt=javabin&version=2} {add=[10061 (1429005417002827776)]} 0 4
[junit4:junit4] 2> 21162 T36 C2 P51329 /update {wt=javabin&version=2} {delete=[10055 (-1429005417020653568)]} 0 0
[junit4:junit4] 2> 21167 T51 C3 P51341 /update {wt=javabin&version=2} {delete=[10055 (-1429005417025896448)]} 0 1
[junit4:junit4] 2> 21175 T34 C2 P51329 /update {wt=javabin&version=2} {add=[10062 (1429005417031139328)]} 0 4
[junit4:junit4] 2> 21184 T52 C3 P51341 /update {wt=javabin&version=2} {add=[10062 (1429005417040576512)]} 0 3
[junit4:junit4] 2> 21252 T31 C2 P51329 /update {wt=javabin&version=2} {add=[10063 (1429005417111879680)]} 0 4
[junit4:junit4] 2> 21258 T55 C3 P51341 /update {wt=javabin&version=2} {add=[10063 (1429005417119219712)]} 0 2
[junit4:junit4] 2> 21343 T33 C2 P51329 /update {wt=javabin&version=2} {add=[10064 (1429005417208348672)]} 0 2
[junit4:junit4] 2> 21363 T54 C3 P51341 /update {wt=javabin&version=2} {add=[10064 (1429005417221980160)]} 0 10
[junit4:junit4] 2> 21367 T17 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 21372 T17 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51350
[junit4:junit4] 2> 21373 T17 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 21373 T17 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2>
[...truncated too long message...]
but Solr cannot talk to ZK
[junit4:junit4] 2> 49161 T60 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> 46944 T20 oazs.SessionTrackerImpl.run SessionTrackerImpl exited loop!
[junit4:junit4] 2> 49163 T60 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 49164 T19 oazs.NIOServerCnxnFactory.run NIOServerCnxn factory exited run method
[junit4:junit4] 2> 49166 T60 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 49168 T17 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4] 2> 49169 T17 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4] 2> 49170 T17 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 49171 T17 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4] 2> 49171 T17 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 2> 49182 T17 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=es_CL, timezone=Africa/Monrovia
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_15 (32-bit)/cpus=2,threads=1,free=5436104,total=39378944
[junit4:junit4] 2> NOTE: All tests run in this JVM: [DisMaxRequestHandlerTest, IndexReaderFactoryTest, RecoveryZkTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.seed=8447793E5D52E206 -Dtests.slow=true -Dtests.locale=es_CL -Dtests.timezone=Africa/Monrovia -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 0.00s | RecoveryZkTest (suite) <<<
[junit4:junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=77, name=coreLoadExecutor-33-thread-1, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4] > at java.lang.Thread.getStackTrace(Thread.java:1567)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
[junit4:junit4] > at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:266)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:222)
[junit4:junit4] > at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:244)
[junit4:junit4] > at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:458)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:733)
[junit4:junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:619)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.createFromZk(CoreContainer.java:874)
[junit4:junit4] > at org.apache.solr.core.CoreContainer.create(CoreContainer.java:957)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:580)
[junit4:junit4] > at org.apache.solr.core.CoreContainer$2.call(CoreContainer.java:575)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
[junit4:junit4] > at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] > Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@13fe0f4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@12c2a3)
[junit4:junit4] > at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4] > at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > ... 1 more
[junit4:junit4] > Throwable #2: com.carrotsearch.randomizedtesting.ResourceDisposalError: Resource in scope SUITE failed to close. Resource was registered from thread Thread[id=79, name=RecoveryThread, state=RUNNABLE, group=TGRP-RecoveryZkTest], registration stack trace below.
[junit4:junit4] > at java.lang.Thread.getStackTrace(Thread.java:1567)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeAtEnd(RandomizedContext.java:150)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.closeAfterSuite(LuceneTestCase.java:520)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.wrapDirectory(LuceneTestCase.java:986)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:878)
[junit4:junit4] > at org.apache.lucene.util.LuceneTestCase.newDirectory(LuceneTestCase.java:870)
[junit4:junit4] > at org.apache.solr.core.MockDirectoryFactory.create(MockDirectoryFactory.java:33)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:266)
[junit4:junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:222)
[junit4:junit4] > at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:383)
[junit4:junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:281)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:153)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:409)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:223)
[junit4:junit4] > Caused by: java.lang.AssertionError: Directory not closed: MockDirWrapper(org.apache.lucene.store.RAMDirectory@cf182 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16bf1ae)
[junit4:junit4] > at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4] > at org.apache.lucene.util.CloseableDirectory.close(CloseableDirectory.java:47)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:602)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2$1.apply(RandomizedRunner.java:599)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedContext.closeResources(RandomizedContext.java:167)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.RandomizedRunner$2.afterAlways(RandomizedRunner.java:615)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
[junit4:junit4] > at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] Completed in 49.35s, 1 test, 2 errors <<< FAILURES!
[...truncated 840 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:381: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:361: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:183: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1213: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:877: There were test failures: 269 suites, 1137 tests, 2 suite-level errors, 18 ignored (12 assumptions)
Total time: 59 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.7.0_15 -server -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure