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/08 08:06:39 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_15) - Build #
2629 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2629/
Java: 32bit/jdk1.7.0_15 -client -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=151, name=coreLoadExecutor-45-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=151, name=coreLoadExecutor-45-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@91c2c lockFactory=org.apache.lucene.store.NativeFSLockFactory@f3d86c)
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=153, 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=153, 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@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a)
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 8860 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 0 T91 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /nn_smm/
[junit4:junit4] 2> 5 T91 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-1362724254272
[junit4:junit4] 2> 17 T91 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 25 T92 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 117 T92 oaz.Environment.logEnv Server environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 117 T92 oaz.Environment.logEnv Server environment:host.name=JenkinsSlave-PC
[junit4:junit4] 2> 117 T92 oaz.Environment.logEnv Server environment:java.version=1.7.0_15
[junit4:junit4] 2> 117 T92 oaz.Environment.logEnv Server environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 118 T92 oaz.Environment.logEnv Server environment:java.home=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre
[junit4:junit4] 2> 118 T92 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> 120 T92 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> 120 T92 oaz.Environment.logEnv Server environment:java.io.tmpdir=.
[junit4:junit4] 2> 121 T92 oaz.Environment.logEnv Server environment:java.compiler=<NA>
[junit4:junit4] 2> 121 T92 oaz.Environment.logEnv Server environment:os.name=Windows 7
[junit4:junit4] 2> 121 T92 oaz.Environment.logEnv Server environment:os.arch=x86
[junit4:junit4] 2> 121 T92 oaz.Environment.logEnv Server environment:os.version=6.1
[junit4:junit4] 2> 121 T92 oaz.Environment.logEnv Server environment:user.name=JenkinsSlave
[junit4:junit4] 2> 122 T92 oaz.Environment.logEnv Server environment:user.home=C:\Users\JenkinsSlave
[junit4:junit4] 2> 122 T92 oaz.Environment.logEnv Server environment:user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 165 T92 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 165 T92 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 165 T92 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 201 T92 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 244 T91 oasc.ZkTestServer.run start zk server on port:54332
[junit4:junit4] 2> 281 T92 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-1362724254270\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4] 2> 351 T91 oaz.Environment.logEnv Client environment:zookeeper.version=3.4.5-1392090, built on 09/30/2012 17:52 GMT
[junit4:junit4] 2> 352 T91 oaz.Environment.logEnv Client environment:host.name=JenkinsSlave-PC
[junit4:junit4] 2> 352 T91 oaz.Environment.logEnv Client environment:java.version=1.7.0_15
[junit4:junit4] 2> 352 T91 oaz.Environment.logEnv Client environment:java.vendor=Oracle Corporation
[junit4:junit4] 2> 353 T91 oaz.Environment.logEnv Client environment:java.home=C:\Users\JenkinsSlave\tools\java\32bit\jdk1.7.0_15\jre
[junit4:junit4] 2> 353 T91 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> 355 T91 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> 356 T91 oaz.Environment.logEnv Client environment:java.io.tmpdir=.
[junit4:junit4] 2> 356 T91 oaz.Environment.logEnv Client environment:java.compiler=<NA>
[junit4:junit4] 2> 356 T91 oaz.Environment.logEnv Client environment:os.name=Windows 7
[junit4:junit4] 2> 356 T91 oaz.Environment.logEnv Client environment:os.arch=x86
[junit4:junit4] 2> 357 T91 oaz.Environment.logEnv Client environment:os.version=6.1
[junit4:junit4] 2> 357 T91 oaz.Environment.logEnv Client environment:user.name=JenkinsSlave
[junit4:junit4] 2> 357 T91 oaz.Environment.logEnv Client environment:user.home=C:\Users\JenkinsSlave
[junit4:junit4] 2> 357 T91 oaz.Environment.logEnv Client environment:user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 362 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@f4a1d3
[junit4:junit4] 2> 457 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 467 T97 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 468 T97 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 1034 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54335
[junit4:junit4] 2> 1068 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54335
[junit4:junit4] 2> 1085 T95 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 1130 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770000 with negotiated timeout 10000 for client /127.0.0.1:54335
[junit4:junit4] 2> 1130 T97 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770000, negotiated timeout = 10000
[junit4:junit4] 2> 1140 T98 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4a1d3 name:ZooKeeperConnection Watcher:127.0.0.1:54332 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1141 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1145 T91 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1259 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770000
[junit4:junit4] 2> 1261 T98 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 1262 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770000 closed
[junit4:junit4] 2> 1263 T93 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d48b1f3770000, 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> 1263 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@14b5923
[junit4:junit4] 2> 1265 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54335 which had sessionid 0x13d48b1f3770000
[junit4:junit4] 2> 1268 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1269 T99 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 1269 T99 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 1270 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54338
[junit4:junit4] 2> 1270 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54338
[junit4:junit4] 2> 1272 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770001 with negotiated timeout 10000 for client /127.0.0.1:54338
[junit4:junit4] 2> 1272 T99 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770001, negotiated timeout = 10000
[junit4:junit4] 2> 1273 T100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14b5923 name:ZooKeeperConnection Watcher:127.0.0.1:54332/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1273 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1280 T91 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1291 T91 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1300 T91 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1308 T91 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1317 T91 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> 1342 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1358 T91 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> 1359 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1383 T91 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> 1384 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1395 T91 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> 1399 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1421 T91 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> 1422 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1436 T91 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> 1437 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1452 T91 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> 1453 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1464 T91 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> 1465 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1474 T91 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> 1474 T91 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1480 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770001
[junit4:junit4] 2> 1482 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770001 closed
[junit4:junit4] 2> 1482 T93 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d48b1f3770001, 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> 1484 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54338 which had sessionid 0x13d48b1f3770001
[junit4:junit4] 2> 1484 T100 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 2462 T91 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 2758 T91 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54339
[junit4:junit4] 2> 2814 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2816 T91 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2816 T91 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-1362724255748
[junit4:junit4] 2> 2816 T91 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-1362724255748\solr.xml
[junit4:junit4] 2> 2817 T91 oasc.CoreContainer.<init> New CoreContainer 8571502
[junit4:junit4] 2> 2818 T91 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-1362724255748\'
[junit4:junit4] 2> 2819 T91 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-1362724255748\'
[junit4:junit4] 2> 2913 T91 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2913 T91 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2913 T91 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2914 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2914 T91 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2914 T91 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2914 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2915 T91 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2915 T91 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 3007 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4503 T91 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4534 T91 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54332/solr
[junit4:junit4] 2> 4572 T91 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4573 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@c20dd6
[junit4:junit4] 2> 4577 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4580 T111 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4581 T111 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 4581 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54344
[junit4:junit4] 2> 4583 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54344
[junit4:junit4] 2> 4613 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770002 with negotiated timeout 20000 for client /127.0.0.1:54344
[junit4:junit4] 2> 4613 T111 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770002, negotiated timeout = 20000
[junit4:junit4] 2> 4615 T112 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c20dd6 name:ZooKeeperConnection Watcher:127.0.0.1:54332 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4615 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4622 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770002
[junit4:junit4] 2> 4627 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770002 closed
[junit4:junit4] 2> 4627 T112 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4636 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54344 which had sessionid 0x13d48b1f3770002
[junit4:junit4] 2> 4638 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 4662 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@2ffc25
[junit4:junit4] 2> 4663 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4665 T113 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 4665 T113 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 4666 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54347
[junit4:junit4] 2> 4666 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54347
[junit4:junit4] 2> 4692 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770003 with negotiated timeout 20000 for client /127.0.0.1:54347
[junit4:junit4] 2> 4692 T113 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770003, negotiated timeout = 20000
[junit4:junit4] 2> 4693 T114 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ffc25 name:ZooKeeperConnection Watcher:127.0.0.1:54332/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4693 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4758 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4793 T91 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 4797 T91 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54339_nn_smm
[junit4:junit4] 2> 4804 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54339_nn_smm Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54339_nn_smm
[junit4:junit4] 2> 4806 T91 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54339_nn_smm
[junit4:junit4] 2> 4817 T91 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 4844 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 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> 4847 T91 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 4867 T91 oasc.Overseer.start Overseer (id=89307496748351491-127.0.0.1:54339_nn_smm-n_0000000000) starting
[junit4:junit4] 2> 4868 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4889 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4893 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4905 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4911 T91 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 4918 T116 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 4925 T91 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 4935 T91 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4974 T115 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 5035 T117 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-1362724255748\collection1
[junit4:junit4] 2> 5036 T117 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 5037 T117 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5038 T117 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 5055 T117 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-1362724255748\collection1\'
[junit4:junit4] 2> 5058 T117 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-1362724255748/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5061 T117 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-1362724255748/collection1/lib/README' to classloader
[junit4:junit4] 2> 5151 T117 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 5242 T117 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5246 T117 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5255 T117 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 6136 T117 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 6148 T117 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 6152 T117 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 6182 T117 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6188 T117 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 6195 T117 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6198 T117 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 6198 T117 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 6198 T117 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 6201 T117 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 6201 T117 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 6201 T117 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-1362724255748\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/control/data\
[junit4:junit4] 2> 6209 T117 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14e28c
[junit4:junit4] 2> 6211 T117 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 6212 T117 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-1362724254270\control\data forceNew: false
[junit4:junit4] 2> 6212 T117 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/control/data\index/
[junit4:junit4] 2> 6214 T117 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 6214 T117 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-1362724254270\control\data\index forceNew: false
[junit4:junit4] 2> 6221 T117 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@103edac lockFactory=org.apache.lucene.store.NativeFSLockFactory@ab7666),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 6221 T117 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 6282 T117 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 6282 T117 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 6283 T117 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 6283 T117 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 6284 T117 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 6284 T117 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 6284 T117 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 6285 T117 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 6286 T117 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 6297 T117 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 6311 T117 oass.SolrIndexSearcher.<init> Opening Searcher@150efee main
[junit4:junit4] 2> 6320 T117 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\control\data\tlog
[junit4:junit4] 2> 6343 T117 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 6343 T117 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 6350 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@150efee main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 6352 T117 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 6353 T117 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 6354 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x55 zxid:0x2a txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4] 2> 6645 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 6646 T115 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:54339_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54339/nn_smm"}
[junit4:junit4] 2> 6646 T115 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 6682 T115 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 6683 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x5d zxid:0x2d txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4] 2> 6729 T114 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> 7498 T117 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 7498 T117 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54339/nn_smm collection:control_collection shard:shard1
[junit4:junit4] 2> 7518 T117 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 7547 T117 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 7674 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:delete cxid:0x77 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> 7707 T117 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 7708 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x78 zxid:0x38 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 7775 T117 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 7776 T117 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 7784 T117 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54339/nn_smm/collection1/
[junit4:junit4] 2> 7785 T117 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 7785 T117 oasc.SyncStrategy.syncToMe http://127.0.0.1:54339/nn_smm/collection1/ has no replicas
[junit4:junit4] 2> 7786 T117 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54339/nn_smm/collection1/
[junit4:junit4] 2> 7786 T117 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 7843 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770003 type:create cxid:0x82 zxid:0x3c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8391 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8417 T114 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> 8478 T117 oasc.ZkController.register We are http://127.0.0.1:54339/nn_smm/collection1/ and leader is http://127.0.0.1:54339/nn_smm/collection1/
[junit4:junit4] 2> 8485 T117 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54339/nn_smm
[junit4:junit4] 2> 8485 T117 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8485 T117 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8486 T117 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8490 T117 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8503 T91 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 8503 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8567 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8582 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 8587 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@520c83
[junit4:junit4] 2> 8589 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8591 T120 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 8592 T120 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 8592 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54350
[junit4:junit4] 2> 8592 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54350
[junit4:junit4] 2> 8594 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770004 with negotiated timeout 10000 for client /127.0.0.1:54350
[junit4:junit4] 2> 8594 T120 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770004, negotiated timeout = 10000
[junit4:junit4] 2> 8594 T121 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@520c83 name:ZooKeeperConnection Watcher:127.0.0.1:54332/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8595 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8597 T91 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 8607 T91 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 9025 T91 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 9032 T91 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54351
[junit4:junit4] 2> 9034 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 9034 T91 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 9034 T91 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-1362724262871
[junit4:junit4] 2> 9034 T91 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-1362724262871\solr.xml
[junit4:junit4] 2> 9036 T91 oasc.CoreContainer.<init> New CoreContainer 7349333
[junit4:junit4] 2> 9036 T91 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-1362724262871\'
[junit4:junit4] 2> 9036 T91 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-1362724262871\'
[junit4:junit4] 2> 9132 T91 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 9133 T91 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 9133 T91 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 9134 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 9135 T91 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 9135 T91 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 9135 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 9136 T91 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 9136 T91 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 9137 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 9154 T91 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 9185 T91 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54332/solr
[junit4:junit4] 2> 9186 T91 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 9186 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1717b35
[junit4:junit4] 2> 9188 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9189 T131 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9190 T131 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 9190 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54356
[junit4:junit4] 2> 9192 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54356
[junit4:junit4] 2> 9218 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770005 with negotiated timeout 20000 for client /127.0.0.1:54356
[junit4:junit4] 2> 9218 T131 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770005, negotiated timeout = 20000
[junit4:junit4] 2> 9220 T132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1717b35 name:ZooKeeperConnection Watcher:127.0.0.1:54332 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9220 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9223 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770005
[junit4:junit4] 2> 9243 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54356 which had sessionid 0x13d48b1f3770005
[junit4:junit4] 2> 9243 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770005 closed
[junit4:junit4] 2> 9243 T132 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 9244 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 9251 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@3dd358
[junit4:junit4] 2> 9253 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 9254 T133 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 9255 T133 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 9255 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54359
[junit4:junit4] 2> 9255 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54359
[junit4:junit4] 2> 9273 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770006 with negotiated timeout 20000 for client /127.0.0.1:54359
[junit4:junit4] 2> 9273 T133 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770006, negotiated timeout = 20000
[junit4:junit4] 2> 9273 T134 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dd358 name:ZooKeeperConnection Watcher:127.0.0.1:54332/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 9274 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9276 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 type:create cxid:0x1 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9294 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 type:create cxid:0x2 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9316 T91 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 9918 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 9921 T115 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:54339_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54339/nn_smm"}
[junit4:junit4] 2> 9965 T134 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> 9966 T114 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> 9966 T121 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> 10321 T91 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54351_nn_smm
[junit4:junit4] 2> 10323 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 type:delete cxid:0xd zxid:0x50 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54351_nn_smm Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54351_nn_smm
[junit4:junit4] 2> 10327 T91 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54351_nn_smm
[junit4:junit4] 2> 10332 T134 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> 10334 T121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 10334 T114 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 10334 T114 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> 10334 T121 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> 10341 T134 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 10358 T135 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-1362724262871\collection1
[junit4:junit4] 2> 10358 T135 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 10359 T135 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 10359 T135 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 10364 T135 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-1362724262871\collection1\'
[junit4:junit4] 2> 10366 T135 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-1362724262871/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 10367 T135 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-1362724262871/collection1/lib/README' to classloader
[junit4:junit4] 2> 10433 T135 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 10515 T135 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 10516 T135 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 10525 T135 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 11342 T135 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 11359 T135 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 11363 T135 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 11386 T135 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 11396 T135 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 11403 T135 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 11405 T135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 11406 T135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 11406 T135 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 11408 T135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 11408 T135 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 11408 T135 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-1362724262871\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty1\
[junit4:junit4] 2> 11409 T135 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14e28c
[junit4:junit4] 2> 11409 T135 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 11410 T135 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-1362724254270\jetty1 forceNew: false
[junit4:junit4] 2> 11410 T135 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty1\index/
[junit4:junit4] 2> 11411 T135 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 11411 T135 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-1362724254270\jetty1\index forceNew: false
[junit4:junit4] 2> 11415 T135 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8cf25e lockFactory=org.apache.lucene.store.NativeFSLockFactory@828c9a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 11415 T135 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 11419 T135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 11419 T135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 11419 T135 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 11420 T135 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 11421 T135 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 11421 T135 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 11421 T135 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 11422 T135 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 11422 T135 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 11434 T135 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 11441 T135 oass.SolrIndexSearcher.<init> Opening Searcher@13428df main
[junit4:junit4] 2> 11441 T135 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty1\tlog
[junit4:junit4] 2> 11443 T135 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 11444 T135 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 11449 T136 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13428df main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 11452 T135 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 11452 T135 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11485 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11486 T115 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:54351_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54351/nn_smm"}
[junit4:junit4] 2> 11486 T115 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 11487 T115 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11531 T134 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> 11532 T114 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> 11532 T121 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> 12457 T135 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12457 T135 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54351/nn_smm collection:collection1 shard:shard1
[junit4:junit4] 2> 12458 T135 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 12548 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 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> 12575 T135 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 12576 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 type:create cxid:0x4b zxid:0x5d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 12618 T135 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 12619 T135 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 12619 T135 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54351/nn_smm/collection1/
[junit4:junit4] 2> 12620 T135 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 12620 T135 oasc.SyncStrategy.syncToMe http://127.0.0.1:54351/nn_smm/collection1/ has no replicas
[junit4:junit4] 2> 12620 T135 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54351/nn_smm/collection1/
[junit4:junit4] 2> 12621 T135 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 12678 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770006 type:create cxid:0x55 zxid:0x61 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13041 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13079 T134 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> 13079 T114 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> 13079 T121 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> 13082 T135 oasc.ZkController.register We are http://127.0.0.1:54351/nn_smm/collection1/ and leader is http://127.0.0.1:54351/nn_smm/collection1/
[junit4:junit4] 2> 13082 T135 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54351/nn_smm
[junit4:junit4] 2> 13083 T135 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 13084 T135 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 13084 T135 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 13089 T135 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13093 T91 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 13093 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 13094 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 13526 T91 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 13533 T91 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54360
[junit4:junit4] 2> 13534 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 13534 T91 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 13534 T91 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-1362724267373
[junit4:junit4] 2> 13535 T91 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-1362724267373\solr.xml
[junit4:junit4] 2> 13535 T91 oasc.CoreContainer.<init> New CoreContainer 3211862
[junit4:junit4] 2> 13535 T91 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-1362724267373\'
[junit4:junit4] 2> 13536 T91 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-1362724267373\'
[junit4:junit4] 2> 13596 T91 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 13596 T91 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 13596 T91 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 13596 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 13597 T91 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 13597 T91 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 13597 T91 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 13599 T91 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 13599 T91 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 13600 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 13618 T91 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 13655 T91 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:54332/solr
[junit4:junit4] 2> 13655 T91 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 13655 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@28c141
[junit4:junit4] 2> 13658 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13659 T147 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13661 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54365
[junit4:junit4] 2> 13661 T147 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 13662 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54365
[junit4:junit4] 2> 13680 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770007 with negotiated timeout 20000 for client /127.0.0.1:54365
[junit4:junit4] 2> 13680 T147 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770007, negotiated timeout = 20000
[junit4:junit4] 2> 13680 T148 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28c141 name:ZooKeeperConnection Watcher:127.0.0.1:54332 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13681 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13683 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770007
[junit4:junit4] 2> 13685 T148 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13685 T93 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13d48b1f3770007, 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> 13685 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770007 closed
[junit4:junit4] 2> 13687 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54365 which had sessionid 0x13d48b1f3770007
[junit4:junit4] 2> 13687 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 13696 T91 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:54332/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@1cf0ffb
[junit4:junit4] 2> 13699 T91 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13700 T149 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:54332. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4] 2> 13701 T149 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:54332, initiating session
[junit4:junit4] 2> 13701 T93 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:54368
[junit4:junit4] 2> 13703 T93 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:54368
[junit4:junit4] 2> 13705 T95 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d48b1f3770008 with negotiated timeout 20000 for client /127.0.0.1:54368
[junit4:junit4] 2> 13705 T149 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:54332, sessionid = 0x13d48b1f3770008, negotiated timeout = 20000
[junit4:junit4] 2> 13706 T150 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cf0ffb name:ZooKeeperConnection Watcher:127.0.0.1:54332/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13706 T91 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13708 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770008 type:create cxid:0x1 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13712 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770008 type:create cxid:0x2 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13717 T91 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 14588 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 14589 T115 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:54351_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54351/nn_smm"}
[junit4:junit4] 2> 14603 T134 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> 14603 T150 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> 14604 T121 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> 14605 T114 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> 14712 T91 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54360_nn_smm
[junit4:junit4] 2> 14713 T96 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d48b1f3770008 type:delete cxid:0xd zxid:0x74 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:54360_nn_smm Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:54360_nn_smm
[junit4:junit4] 2> 14715 T91 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54360_nn_smm
[junit4:junit4] 2> 14720 T134 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> 14722 T150 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 14722 T150 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> 14723 T114 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 14723 T114 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> 14724 T121 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 14725 T121 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> 14727 T134 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 14739 T151 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-1362724267373\collection1
[junit4:junit4] 2> 14739 T151 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 14740 T151 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 14741 T151 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 14743 T151 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-1362724267373\collection1\'
[junit4:junit4] 2> 14744 T151 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-1362724267373/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 14745 T151 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-1362724267373/collection1/lib/README' to classloader
[junit4:junit4] 2> 14808 T151 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 14910 T151 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 14912 T151 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 14921 T151 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 15761 T151 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 15773 T151 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 15778 T151 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 15815 T151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15821 T151 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 15827 T151 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15830 T151 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 15831 T151 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 15831 T151 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 15833 T151 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 15833 T151 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 15833 T151 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-1362724267373\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty2\
[junit4:junit4] 2> 15833 T151 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14e28c
[junit4:junit4] 2> 15834 T151 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 15834 T151 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-1362724254270\jetty2 forceNew: false
[junit4:junit4] 2> 15834 T151 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty2\index/
[junit4:junit4] 2> 15836 T151 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 15837 T151 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-1362724254270\jetty2\index forceNew: false
[junit4:junit4] 2> 15841 T151 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bdf85 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17938ac),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 15841 T151 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 15845 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 15845 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 15846 T151 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 15848 T151 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 15848 T151 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 15848 T151 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 15849 T151 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 15850 T151 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 15850 T151 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 15861 T151 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 15869 T151 oass.SolrIndexSearcher.<init> Opening Searcher@1794c10 main
[junit4:junit4] 2> 15869 T151 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty2\tlog
[junit4:junit4] 2> 15871 T151 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 15871 T151 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 15877 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1794c10 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 15879 T151 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 15879 T151 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16104 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16106 T115 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:54360_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54360/nn_smm"}
[junit4:junit4] 2> 16107 T115 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 16107 T115 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 16151 T134 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> 16152 T114 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> 16153 T150 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> 16156 T121 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> 16880 T151 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 16880 T151 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54360/nn_smm collection:collection1 shard:shard1
[junit4:junit4] 2> 16890 T151 oasc.ZkController.register We are http://127.0.0.1:54360/nn_smm/collection1/ and leader is http://127.0.0.1:54351/nn_smm/collection1/
[junit4:junit4] 2> 16890 T151 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54360/nn_smm
[junit4:junit4] 2> 16890 T151 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 16891 T151 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@b80f9d url=http://127.0.0.1:54360/nn_smm/collection1 node=127.0.0.1:54360_nn_smm C5_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:54360_nn_smm, base_url=http://127.0.0.1:54360/nn_smm}
[junit4:junit4] 2> 16901 T153 C5 P54360 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 16902 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 16902 T151 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 16903 T153 C5 P54360 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 16903 T153 C5 P54360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 16906 T91 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 16907 T91 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 16907 T91 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16907 T153 C5 P54360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 16921 T91 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17690 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 17692 T115 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:54360_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54360/nn_smm"}
[junit4:junit4] 2> 17770 T134 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> 17771 T114 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> 17771 T150 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> 17773 T121 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> 17945 T126 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=3&state=recovering&nodeName=127.0.0.1:54360_nn_smm&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=13
[junit4:junit4] 2> ASYNC NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@12ce07a url=http://127.0.0.1:54339/nn_smm/collection1 node=127.0.0.1:54339_nn_smm C6_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:54339_nn_smm, base_url=http://127.0.0.1:54339/nn_smm, leader=true}
[junit4:junit4] 2> 18095 T108 C6 P54339 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@103edac lockFactory=org.apache.lucene.store.NativeFSLockFactory@ab7666),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18096 T108 C6 P54339 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18127 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10001 (1428919966609965057)]} 0 98
[junit4:junit4] 2> 18127 T108 C6 P54339 /update {wt=javabin&version=2} {add=[1 (1428919966609965056)]} 0 85
[junit4:junit4] 2> ASYNC NEW_CORE C7 name=collection1 org.apache.solr.core.SolrCore@153b63f url=http://127.0.0.1:54351/nn_smm/collection1 node=127.0.0.1:54351_nn_smm C7_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54351_nn_smm, base_url=http://127.0.0.1:54351/nn_smm, leader=true}
[junit4:junit4] 2> 18164 T128 C7 P54351 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8cf25e lockFactory=org.apache.lucene.store.NativeFSLockFactory@828c9a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18164 T128 C7 P54351 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> C5_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:54360_nn_smm, base_url=http://127.0.0.1:54360/nn_smm}
[junit4:junit4] 2> 18218 T142 C5 P54360 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@bdf85 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17938ac),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 18218 T142 C5 P54360 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 18221 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10001 (1428919966682316801)]} 0 7
[junit4:junit4] 2> 18232 T129 C7 P54351 /update {wt=javabin&version=2} {add=[10001 (1428919966682316801)]} 0 80
[junit4:junit4] 2> 18233 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1428919966682316800)]} 0 7
[junit4:junit4] 2> 18234 T128 C7 P54351 /update {wt=javabin&version=2} {add=[1 (1428919966682316800)]} 0 82
[junit4:junit4] 2> 18305 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10002 (1428919966829117440)]} 0 5
[junit4:junit4] 2> 18308 T107 C6 P54339 /update {wt=javabin&version=2} {add=[2 (1428919966829117441)]} 0 8
[junit4:junit4] 2> 18320 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10002 (1428919966844846080)]} 0 1
[junit4:junit4] 2> 18321 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10002 (1428919966844846080)]} 0 5
[junit4:junit4] 2> 18323 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1428919966844846081)]} 0 1
[junit4:junit4] 2> 18325 T126 C7 P54351 /update {wt=javabin&version=2} {add=[2 (1428919966844846081)]} 0 9
[junit4:junit4] 2> 18390 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10002 (-1428919966917197824)]} 0 7
[junit4:junit4] 2> 18391 T108 C6 P54339 /update {wt=javabin&version=2} {delete=[2 (-1428919966921392128)]} 0 3
[junit4:junit4] 2> 18410 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10002 (-1428919966929780736)]} 0 2
[junit4:junit4] 2> 18410 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[10002 (-1428919966929780736)]} 0 14
[junit4:junit4] 2> 18411 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[2 (-1428919966930829312)]} 0 3
[junit4:junit4] 2> 18412 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[2 (-1428919966930829312)]} 0 16
[junit4:junit4] 2> 18415 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10003 (1428919966947606528)]} 0 1
[junit4:junit4] 2> 18419 T106 C6 P54339 /update {wt=javabin&version=2} {add=[3 (1428919966951800832)]} 0 2
[junit4:junit4] 2> 18425 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10003 (1428919966954946560)]} 0 1
[junit4:junit4] 2> 18427 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1428919966957043712)]} 0 0
[junit4:junit4] 2> 18429 T129 C7 P54351 /update {wt=javabin&version=2} {add=[10003 (1428919966954946560)]} 0 8
[junit4:junit4] 2> 18430 T128 C7 P54351 /update {wt=javabin&version=2} {add=[3 (1428919966957043712)]} 0 7
[junit4:junit4] 2> 18496 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10004 (1428919967032541184)]} 0 1
[junit4:junit4] 2> 18498 T107 C6 P54339 /update {wt=javabin&version=2} {add=[4 (1428919967034638336)]} 0 1
[junit4:junit4] 2> 18504 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10004 (1428919967037784064)]} 0 1
[junit4:junit4] 2> 18505 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10004 (1428919967037784064)]} 0 5
[junit4:junit4] 2> 18509 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1428919967039881216)]} 0 1
[junit4:junit4] 2> 18510 T125 C7 P54351 /update {wt=javabin&version=2} {add=[4 (1428919967039881216)]} 0 9
[junit4:junit4] 2> 18560 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10004 (-1428919967100698624)]} 0 1
[junit4:junit4] 2> 18568 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10004 (-1428919967104892928)]} 0 2
[junit4:junit4] 2> 18570 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[10004 (-1428919967104892928)]} 0 6
[junit4:junit4] 2> 18570 T108 C6 P54339 /update {wt=javabin&version=2} {delete=[4 (-1428919967111184384)]} 0 3
[junit4:junit4] 2> 18576 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10005 (1428919967116427264)]} 0 1
[junit4:junit4] 2> 18583 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[4 (-1428919967119572992)]} 0 3
[junit4:junit4] 2> 18584 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[4 (-1428919967119572992)]} 0 10
[junit4:junit4] 2> 18586 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10005 (1428919967124815872)]} 0 1
[junit4:junit4] 2> 18588 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10005 (1428919967124815872)]} 0 8
[junit4:junit4] 2> 18592 T106 C6 P54339 /update {wt=javabin&version=2} {add=[5 (1428919967133204480)]} 0 1
[junit4:junit4] 2> 18600 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1428919967137398784)]} 0 1
[junit4:junit4] 2> 18601 T126 C7 P54351 /update {wt=javabin&version=2} {add=[5 (1428919967137398784)]} 0 6
[junit4:junit4] 2> 18664 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10006 (1428919967209750528)]} 0 0
[junit4:junit4] 2> 18675 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10006 (1428919967214993408)]} 0 1
[junit4:junit4] 2> 18676 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10006 (1428919967214993408)]} 0 8
[junit4:junit4] 2> 18678 T107 C6 P54339 /update {wt=javabin&version=2} {add=[6 (1428919967224430592)]} 0 0
[junit4:junit4] 2> 18690 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1428919967229673472)]} 0 2
[junit4:junit4] 2> 18691 T125 C7 P54351 /update {wt=javabin&version=2} {add=[6 (1428919967229673472)]} 0 8
[junit4:junit4] 2> 18721 T105 C6 P54339 /update {wt=javabin&version=2} {add=[10007 (1428919967269519360)]} 0 0
[junit4:junit4] 2> 18730 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10007 (1428919967273713664)]} 0 2
[junit4:junit4] 2> 18731 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10007 (1428919967273713664)]} 0 6
[junit4:junit4] 2> 18738 T109 C6 P54339 /update {wt=javabin&version=2} {add=[7 (1428919967286296576)]} 0 2
[junit4:junit4] 2> 18744 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1428919967289442304)]} 0 1
[junit4:junit4] 2> 18745 T129 C7 P54351 /update {wt=javabin&version=2} {add=[7 (1428919967289442304)]} 0 5
[junit4:junit4] 2> 18793 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10008 (1428919967345016832)]} 0 1
[junit4:junit4] 2> 18805 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10008 (1428919967350259712)]} 0 1
[junit4:junit4] 2> 18805 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10008 (1428919967350259712)]} 0 7
[junit4:junit4] 2> 18807 T110 C6 P54339 /update {wt=javabin&version=2} {add=[8 (1428919967358648320)]} 0 2
[junit4:junit4] 2> 18817 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1428919967364939776)]} 0 2
[junit4:junit4] 2> 18818 T126 C7 P54351 /update {wt=javabin&version=2} {add=[8 (1428919967364939776)]} 0 6
[junit4:junit4] 2> 18819 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10009 (1428919967371231232)]} 0 1
[junit4:junit4] 2> 18828 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10009 (1428919967377522688)]} 0 1
[junit4:junit4] 2> 18829 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10009 (1428919967377522688)]} 0 6
[junit4:junit4] 2> 18833 T108 C6 P54339 /update {wt=javabin&version=2} {add=[9 (1428919967385911296)]} 0 1
[junit4:junit4] 2> 18844 T91 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 54360
[junit4:junit4] 2> 18844 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1428919967390105600)]} 0 5
[junit4:junit4] 2> 18844 T91 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=3211862
[junit4:junit4] 2> 18845 T125 C7 P54351 /update {wt=javabin&version=2} {add=[9 (1428919967390105600)]} 0 9
[junit4:junit4] 2> 18862 T105 C6 P54339 /update {wt=javabin&version=2} {add=[10010 (1428919967414222848)]} 0 3
[junit4:junit4] 2> 18872 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10010 (1428919967422611456)]} 0 1
[junit4:junit4] 2> 18874 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10010 (1428919967422611456)]} 0 7
[junit4:junit4] 2> 18876 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10 (1428919967431000064)]} 0 5
[junit4:junit4] 2> 18885 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1428919967435194368)]} 0 1
[junit4:junit4] 2> 18887 T129 C7 P54351 /update {wt=javabin&version=2} {add=[10 (1428919967435194368)]} 0 8
[junit4:junit4] 2> 18911 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[10006 (-1428919967468748800)]} 0 1
[junit4:junit4] 2> 18919 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10006 (-1428919967473991680)]} 0 1
[junit4:junit4] 2> 18919 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[10006 (-1428919967473991680)]} 0 4
[junit4:junit4] 2> 18926 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10011 (1428919967484477440)]} 0 1
[junit4:junit4] 2> 18926 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[6 (-1428919967484477441)]} 0 0
[junit4:junit4] 2> 18941 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10011 (1428919967490768896)]} 0 5
[junit4:junit4] 2> 18943 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10011 (1428919967490768896)]} 0 11
[junit4:junit4] 2> 18944 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[6 (-1428919967492866048)]} 0 6
[junit4:junit4] 2> 18945 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[6 (-1428919967492866048)]} 0 11
[junit4:junit4] 2> 18948 T108 C6 P54339 /update {wt=javabin&version=2} {add=[11 (1428919967506497536)]} 0 1
[junit4:junit4] 2> 18959 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1428919967514886144)]} 0 0
[junit4:junit4] 2> 18961 T127 C7 P54351 /update {wt=javabin&version=2} {add=[11 (1428919967514886144)]} 0 7
[junit4:junit4] 2> 18963 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10007 (-1428919967523274752)]} 0 0
[junit4:junit4] 2> 18969 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10007 (-1428919967526420480)]} 0 1
[junit4:junit4] 2> 18970 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10007 (-1428919967526420480)]} 0 4
[junit4:junit4] 2> 18974 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10012 (1428919967534809088)]} 0 2
[junit4:junit4] 2> 18981 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[7 (-1428919967542149120)]} 0 1
[junit4:junit4] 2> 18984 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10012 (1428919967540051968)]} 0 1
[junit4:junit4] 2> 18985 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10012 (1428919967540051968)]} 0 6
[junit4:junit4] 2> 18989 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[7 (-1428919967547392000)]} 0 0
[junit4:junit4] 2> 18989 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[7 (-1428919967547392000)]} 0 3
[junit4:junit4] 2> 18995 T107 C6 P54339 /update {wt=javabin&version=2} {add=[12 (1428919967555780608)]} 0 1
[junit4:junit4] 2> 19002 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1428919967561023488)]} 0 0
[junit4:junit4] 2> 19002 T130 C7 P54351 /update {wt=javabin&version=2} {add=[12 (1428919967561023488)]} 0 4
[junit4:junit4] 2> 19018 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[10009 (-1428919967580946432)]} 0 0
[junit4:junit4] 2> 19025 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10009 (-1428919967584092160)]} 0 0
[junit4:junit4] 2> 19026 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[10009 (-1428919967584092160)]} 0 5
[junit4:junit4] 2> 19030 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10013 (1428919967593529344)]} 0 1
[junit4:junit4] 2> 19037 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10013 (1428919967596675072)]} 0 1
[junit4:junit4] 2> 19038 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[9 (-1428919967601917952)]} 0 0
[junit4:junit4] 2> 19039 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10013 (1428919967596675072)]} 0 6
[junit4:junit4] 2> 19043 T144 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[9 (-1428919967605063680)]} 0 0
[junit4:junit4] 2> 19044 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[9 (-1428919967605063680)]} 0 4
[junit4:junit4] 2> 19047 T109 C6 P54339 /update {wt=javabin&version=2} {add=[13 (1428919967610306560)]} 0 1
[junit4:junit4] 2> 19054 T145 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1428919967615549440)]} 0 1
[junit4:junit4] 2> 19055 T126 C7 P54351 /update {wt=javabin&version=2} {add=[13 (1428919967615549440)]} 0 4
[junit4:junit4] 2> 19104 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[10010 (-1428919967671123968)]} 0 0
[junit4:junit4] 2> 19110 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10010 (-1428919967673221120)]} 0 1
[junit4:junit4] 2> 19111 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[10010 (-1428919967673221120)]} 0 5
[junit4:junit4] 2> 19114 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10014 (1428919967680561152)]} 0 1
[junit4:junit4] 2> 19121 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[10 (-1428919967687901184)]} 0 1
[junit4:junit4] 2> 19123 T143 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10014 (1428919967684755456)]} 0 1
[junit4:junit4] 2> 19124 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10014 (1428919967684755456)]} 0 7
[junit4:junit4] 2> 19127 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10 (-1428919967693144064)]} 0 0
[junit4:junit4] 2> 19128 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[10 (-1428919967693144064)]} 0 3
[junit4:junit4] 2> 19132 T105 C6 P54339 /update {wt=javabin&version=2} {add=[14 (1428919967699435520)]} 0 1
[junit4:junit4] 2> 19137 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1428919967702581248)]} 0 0
[junit4:junit4] 2> 19139 T127 C7 P54351 /update {wt=javabin&version=2} {add=[14 (1428919967702581248)]} 0 5
[junit4:junit4] 2> 19181 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19182 T115 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:54360_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54360/nn_smm"}
[junit4:junit4] 2> 19200 T134 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> 19200 T114 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> 19200 T150 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> 19200 T121 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> 19202 T109 C6 P54339 /update {wt=javabin&version=2} {delete=[10011 (-1428919967773884416)]} 0 1
[junit4:junit4] 2> 19206 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10011 (-1428919967777030144)]} 0 1
[junit4:junit4] 2> 19213 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10015 (1428919967784370176)]} 0 1
[junit4:junit4] 2> 19214 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[11 (-1428919967786467328)]} 0 0
[junit4:junit4] 2> 19219 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10015 (1428919967790661632)]} 0 1
[junit4:junit4] 2> 19220 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[11 (-1428919967792758784)]} 0 0
[junit4:junit4] 2> 19227 T110 C6 P54339 /update {wt=javabin&version=2} {add=[15 (1428919967799050240)]} 0 1
[junit4:junit4] 2> 19230 T130 C7 P54351 /update {wt=javabin&version=2} {add=[15 (1428919967803244544)]} 0 1
[junit4:junit4] 2> 19304 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10016 (1428919967879790592)]} 0 2
[junit4:junit4] 2> 19307 T125 C7 P54351 /update {wt=javabin&version=2} {add=[10016 (1428919967883984896)]} 0 0
[junit4:junit4] 2> 19314 T105 C6 P54339 /update {wt=javabin&version=2} {add=[16 (1428919967891324928)]} 0 0
[junit4:junit4] 2> 19319 T127 C7 P54351 /update {wt=javabin&version=2} {add=[16 (1428919967895519232)]} 0 2
[junit4:junit4] 2> 19341 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10017 (1428919967918587904)]} 0 1
[junit4:junit4] 2> 19343 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10017 (1428919967921733632)]} 0 0
[junit4:junit4] 2> 19350 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10018 (1428919967928025088)]} 0 1
[junit4:junit4] 2> 19353 T107 C6 P54339 /update {wt=javabin&version=2} {add=[17 (1428919967931170816)]} 0 1
[junit4:junit4] 2> 19354 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10018 (1428919967933267968)]} 0 1
[junit4:junit4] 2> 19358 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10019 (1428919967936413696)]} 0 1
[junit4:junit4] 2> 19358 T130 C7 P54351 /update {wt=javabin&version=2} {add=[17 (1428919967937462272)]} 0 0
[junit4:junit4] 2> 19361 T125 C7 P54351 /update {wt=javabin&version=2} {add=[10019 (1428919967940608000)]} 0 0
[junit4:junit4] 2> 19364 T108 C6 P54339 /update {wt=javabin&version=2} {add=[18 (1428919967942705152)]} 0 1
[junit4:junit4] 2> 19368 T129 C7 P54351 /update {wt=javabin&version=2} {add=[18 (1428919967946899456)]} 0 1
[junit4:junit4] 2> 19374 T105 C6 P54339 /update {wt=javabin&version=2} {add=[19 (1428919967953190912)]} 0 1
[junit4:junit4] 2> 19375 T127 C7 P54351 /update {wt=javabin&version=2} {add=[19 (1428919967955288064)]} 0 0
[junit4:junit4] 2> 19436 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10020 (1428919968018202624)]} 0 1
[junit4:junit4] 2> 19441 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10020 (1428919968024494080)]} 0 0
[junit4:junit4] 2> 19449 T106 C6 P54339 /update {wt=javabin&version=2} {add=[20 (1428919968031834112)]} 0 1
[junit4:junit4] 2> 19453 T128 C7 P54351 /update {wt=javabin&version=2} {add=[20 (1428919968036028416)]} 0 1
[junit4:junit4] 2> 19535 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10021 (1428919968122011648)]} 0 1
[junit4:junit4] 2> 19538 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10021 (1428919968125157376)]} 0 1
[junit4:junit4] 2> 19543 T108 C6 P54339 /update {wt=javabin&version=2} {add=[21 (1428919968131448832)]} 0 1
[junit4:junit4] 2> 19547 T125 C7 P54351 /update {wt=javabin&version=2} {add=[21 (1428919968134594560)]} 0 1
[junit4:junit4] 2> 19594 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10012 (-1428919968184926208)]} 0 0
[junit4:junit4] 2> 19596 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10012 (-1428919968187023360)]} 0 0
[junit4:junit4] 2> 19600 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10022 (1428919968190169088)]} 0 1
[junit4:junit4] 2> 19603 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[12 (-1428919968194363392)]} 0 1
[junit4:junit4] 2> 19603 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10022 (1428919968194363392)]} 0 1
[junit4:junit4] 2> 19608 T126 C7 P54351 /update {wt=javabin&version=2} {delete=[12 (-1428919968199606272)]} 0 1
[junit4:junit4] 2> 19611 T110 C6 P54339 /update {wt=javabin&version=2} {add=[22 (1428919968201703424)]} 0 1
[junit4:junit4] 2> 19615 T128 C7 P54351 /update {wt=javabin&version=2} {add=[22 (1428919968205897728)]} 0 1
[junit4:junit4] 2> 19633 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[10013 (-1428919968225820672)]} 0 1
[junit4:junit4] 2> 19636 T130 C7 P54351 /update {wt=javabin&version=2} {delete=[10013 (-1428919968228966400)]} 0 0
[junit4:junit4] 2> 19640 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10023 (1428919968233160704)]} 0 1
[junit4:junit4] 2> 19642 T125 C7 P54351 /update {wt=javabin&version=2} {add=[10023 (1428919968235257856)]} 0 0
[junit4:junit4] 2> 19645 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[13 (-1428919968238403584)]} 0 1
[junit4:junit4] 2> 19649 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[13 (-1428919968242597888)]} 0 1
[junit4:junit4] 2> 19654 T109 C6 P54339 /update {wt=javabin&version=2} {add=[23 (1428919968246792192)]} 0 2
[junit4:junit4] 2> 19657 T127 C7 P54351 /update {wt=javabin&version=2} {add=[23 (1428919968250986496)]} 0 1
[junit4:junit4] 2> 19696 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[10014 (-1428919968291880960)]} 0 1
[junit4:junit4] 2> 19699 T126 C7 P54351 /update {wt=javabin&version=2} {delete=[10014 (-1428919968295026688)]} 0 1
[junit4:junit4] 2> 19703 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10024 (1428919968298172416)]} 0 1
[junit4:junit4] 2> 19707 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10024 (1428919968303415296)]} 0 1
[junit4:junit4] 2> 19711 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[14 (-1428919968306561024)]} 0 1
[junit4:junit4] 2> 19715 T130 C7 P54351 /update {wt=javabin&version=2} {delete=[14 (-1428919968311803904)]} 0 1
[junit4:junit4] 2> 19718 T108 C6 P54339 /update {wt=javabin&version=2} {add=[24 (1428919968313901056)]} 0 1
[junit4:junit4] 2> 19722 T125 C7 P54351 /update {wt=javabin&version=2} {add=[24 (1428919968318095360)]} 0 1
[junit4:junit4] 2> 19778 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10017 (-1428919968377864192)]} 0 2
[junit4:junit4] 2> 19783 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[10017 (-1428919968383107072)]} 0 0
[junit4:junit4] 2> 19789 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10025 (1428919968389398528)]} 0 1
[junit4:junit4] 2> 19792 T109 C6 P54339 /update {wt=javabin&version=2} {delete=[17 (-1428919968392544256)]} 0 1
[junit4:junit4] 2> 19803 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10025 (1428919968404078592)]} 0 0
[junit4:junit4] 2> 19805 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[17 (-1428919968406175744)]} 0 0
[junit4:junit4] 2> 19809 T110 C6 P54339 /update {wt=javabin&version=2} {add=[25 (1428919968409321472)]} 0 1
[junit4:junit4] 2> 19814 T130 C7 P54351 /update {wt=javabin&version=2} {add=[25 (1428919968414564352)]} 0 1
[junit4:junit4] 2> 19835 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[10018 (-1428919968437633024)]} 0 1
[junit4:junit4] 2> 19839 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10018 (-1428919968441827328)]} 0 1
[junit4:junit4] 2> 19845 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10026 (1428919968447070208)]} 0 1
[junit4:junit4] 2> 19848 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[18 (-1428919968451264512)]} 0 3
[junit4:junit4] 2> 19850 T125 C7 P54351 /update {wt=javabin&version=2} {add=[10026 (1428919968453361664)]} 0 0
[junit4:junit4] 2> 19854 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[18 (-1428919968456507392)]} 0 0
[junit4:junit4] 2> 19859 T109 C6 P54339 /update {wt=javabin&version=2} {add=[26 (1428919968460701696)]} 0 2
[junit4:junit4] 2> 19863 T126 C7 P54351 /update {wt=javabin&version=2} {add=[26 (1428919968466993152)]} 0 0
[junit4:junit4] 2> C5_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:54360_nn_smm, base_url=http://127.0.0.1:54360/nn_smm}
[junit4:junit4] 2> 19879 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:54351/nn_smm/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 19900 T153 C5 P54360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 19902 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10027 (1428919968505790464)]} 0 3
[junit4:junit4] 2> 19907 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10027 (1428919968512081920)]} 0 2
[junit4:junit4] 2> 19915 T110 C6 P54339 /update {wt=javabin&version=2} {add=[27 (1428919968519421952)]} 0 2
[junit4:junit4] 2> 19926 T130 C7 P54351 /update {wt=javabin&version=2} {add=[27 (1428919968523616256)]} 0 9
[junit4:junit4] 2> 19929 T153 C5 P54360 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:54360/nn_smm START replicas=[http://127.0.0.1:54351/nn_smm/collection1/] nUpdates=100
[junit4:junit4] 2> 19951 T153 C5 P54360 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 19951 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 19951 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 19951 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 19951 T153 C5 P54360 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty2\tlog\tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 19952 T153 C5 P54360 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:54351/nn_smm/collection1/. core=collection1
[junit4:junit4] 2> 19952 T153 C5 P54360 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 19962 T129 C7 P54351 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 19964 T125 C7 P54351 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 19972 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10028 (1428919968581287936)]} 0 0
[junit4:junit4] 2> 19980 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10028 (1428919968586530816)]} 0 4
[junit4:junit4] 2> 19991 T125 C7 P54351 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8cf25e lockFactory=org.apache.lucene.store.NativeFSLockFactory@828c9a),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8cf25e lockFactory=org.apache.lucene.store.NativeFSLockFactory@828c9a),segFN=segments_2,generation=2,filenames=[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0_SimpleText_0.pst, _0.nvd, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4:junit4] 2> 19992 T125 C7 P54351 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0_SimpleText_0.pst, _0.nvd, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0.fdt]
[junit4:junit4] 2> 19994 T105 C6 P54339 /update {wt=javabin&version=2} {add=[28 (1428919968603308032)]} 0 3
[junit4:junit4] 2> 20004 T126 C7 P54351 /update {wt=javabin&version=2} {add=[28 (1428919968612745216)]} 0 2
[junit4:junit4] 2> 20005 T125 C7 P54351 oass.SolrIndexSearcher.<init> Opening Searcher@1df41c8 realtime
[junit4:junit4] 2> 20005 T125 C7 P54351 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 20005 T125 C7 P54351 /update {waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 41
[junit4:junit4] 2> 20036 T109 C6 P54339 /update {wt=javabin&version=2} {delete=[10019 (-1428919968648396800)]} 0 1
[junit4:junit4] 2> 20039 T130 C7 P54351 /update {wt=javabin&version=2} {delete=[10019 (-1428919968651542528)]} 0 1
[junit4:junit4] 2> 20044 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10029 (1428919968655736832)]} 0 1
[junit4:junit4] 2> 20051 T129 C7 P54351 /update {wt=javabin&version=2} {add=[10029 (1428919968663076864)]} 0 1
[junit4:junit4] 2> 20055 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[19 (-1428919968668319744)]} 0 0
[junit4:junit4] 2> 20058 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[19 (-1428919968671465472)]} 0 0
[junit4:junit4] 2> 20062 T107 C6 P54339 /update {wt=javabin&version=2} {add=[29 (1428919968674611200)]} 0 1
[junit4:junit4] 2> 20067 T126 C7 P54351 /update {wt=javabin&version=2} {add=[29 (1428919968679854080)]} 0 1
[junit4:junit4] 2> 20068 T153 C5 P54360 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20068 T153 C5 P54360 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 20083 T153 C5 P54360 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 20125 T125 C7 P54351 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 20125 T125 C7 P54351 REQ /replication {command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=41
[junit4:junit4] 2> 20126 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 20126 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 20126 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 20130 T108 C6 P54339 /update {wt=javabin&version=2} {delete=[10022 (-1428919968745914368)]} 0 1
[junit4:junit4] 2> 20130 T130 C7 P54351 REQ /replication {command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 20131 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 20
[junit4:junit4] 2> 20133 T153 C5 P54360 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-1362724254270\jetty2\index.20130308153114396 forceNew: false
[junit4:junit4] 2> 20134 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a) fullCopy=true
[junit4:junit4] 2> 20136 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10022 (-1428919968753254400)]} 0 0
[junit4:junit4] 2> 20140 T105 C6 P54339 /update {wt=javabin&version=2} {add=[10030 (1428919968757448704)]} 0 0
[junit4:junit4] 2> 20145 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10030 (1428919968761643008)]} 0 1
[junit4:junit4] 2> 20147 T127 C7 P54351 REQ /replication {file=_0_NestedPulsing_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=4
[junit4:junit4] 2> 20151 T109 C6 P54339 /update {wt=javabin&version=2} {delete=[22 (-1428919968768983040)]} 0 0
[junit4:junit4] 2> 20154 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[22 (-1428919968772128768)]} 0 0
[junit4:junit4] 2> 20158 T106 C6 P54339 /update {wt=javabin&version=2} {add=[30 (1428919968776323072)]} 0 0
[junit4:junit4] 2> 20161 T128 C7 P54351 /update {wt=javabin&version=2} {add=[30 (1428919968778420224)]} 0 1
[junit4:junit4] 2> 20161 T130 C7 P54351 REQ /replication {file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20165 T129 C7 P54351 REQ /replication {file=_0_Lucene42_0.dvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20168 T126 C7 P54351 REQ /replication {file=_0_Memory_0.ram&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20171 T127 C7 P54351 REQ /replication {file=_0_Lucene41_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20174 T125 C7 P54351 REQ /replication {file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20185 T128 C7 P54351 REQ /replication {file=_0_Lucene42_0.dvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20188 T130 C7 P54351 REQ /replication {file=_0_NestedPulsing_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20191 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10031 (1428919968809877504)]} 0 1
[junit4:junit4] 2> 20192 T129 C7 P54351 REQ /replication {file=_0.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20194 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10031 (1428919968814071808)]} 0 1
[junit4:junit4] 2> 20195 T127 C7 P54351 REQ /replication {file=_0_NestedPulsing_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20199 T125 C7 P54351 REQ /replication {file=_0_NestedPulsing_0.pos&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 20203 T128 C7 P54351 REQ /replication {file=_0_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 20205 T107 C6 P54339 /update {wt=javabin&version=2} {add=[31 (1428919968825606144)]} 0 0
[junit4:junit4] 2> 20210 T130 C7 P54351 /update {wt=javabin&version=2} {add=[31 (1428919968828751872)]} 0 2
[junit4:junit4] 2> 20211 T130 C7 P54351 REQ /replication {file=_0.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 20213 T126 C7 P54351 REQ /replication {file=_0_SimpleText_0.pst&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20217 T127 C7 P54351 REQ /replication {file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20221 T125 C7 P54351 REQ /replication {file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20225 T128 C7 P54351 REQ /replication {file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20232 T108 C6 P54339 /update {wt=javabin&version=2} {delete=[10024 (-1428919968853917696)]} 0 0
[junit4:junit4] 2> 20235 T130 C7 P54351 REQ /replication {file=_0_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 20236 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10024 (-1428919968857063424)]} 0 1
[junit4:junit4] 2> 20238 T126 C7 P54351 REQ /replication {file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20239 T105 C6 P54339 /update {wt=javabin&version=2} {add=[10032 (1428919968860209152)]} 0 1
[junit4:junit4] 2> 20242 T125 C7 P54351 REQ /replication {file=_0_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 20244 T153 C5 P54360 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 20244 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10032 (1428919968864403456)]} 0 2
[junit4:junit4] 2> 20245 T109 C6 P54339 /update {wt=javabin&version=2} {delete=[24 (-1428919968866500608)]} 0 1
[junit4:junit4] 2> 20245 T153 C5 P54360 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130308153114396
[junit4:junit4] 2> 20247 T128 C7 P54351 /update {wt=javabin&version=2} {delete=[24 (-1428919968869646336)]} 0 0
[junit4:junit4] 2> 20252 T106 C6 P54339 /update {wt=javabin&version=2} {add=[32 (1428919968873840640)]} 0 1
[junit4:junit4] 2> 20252 T153 C5 P54360 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 20252 T153 C5 P54360 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 20252 T153 C5 P54360 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4] 2> 20257 T153 C5 P54360 oasc.SolrCore.getNewIndexDir New index directory detected: old=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty2\index/ new=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270/jetty2\index.20130308153114396
[junit4:junit4] 2> 20257 T130 C7 P54351 /update {wt=javabin&version=2} {add=[32 (1428919968880132096)]} 0 1
[junit4:junit4] 2> 20259 T153 C5 P54360 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a),segFN=segments_2,generation=2,filenames=[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4] 2> 20260 T153 C5 P54360 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4] 2> 20260 T153 C5 P54360 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 20261 T153 C5 P54360 oass.SolrIndexSearcher.<init> Opening Searcher@ca8d60 main
[junit4:junit4] 2> 20263 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ca8d60 main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C54/24)}
[junit4:junit4] 2> 20264 T153 C5 P54360 oash.SnapPuller$2.preClose removing old index files MockDirWrapper(org.apache.lucene.store.RAMDirectory@bdf85 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17938ac)
[junit4:junit4] 2> 20264 T153 C5 P54360 oasc.CachingDirectoryFactory.closeDirectory Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty2\index
[junit4:junit4] 2> 20264 T153 C5 P54360 oash.SnapPuller$2.postClose removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@bdf85 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17938ac)
[junit4:junit4] 2> 20269 T153 C5 P54360 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 20269 T161 C5 P54360 oasu.UpdateLog$LogReplayer.doReplay WARNING Starting log replay tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1362724254270\jetty2\tlog\tlog.0000000000000000000 refcount=2} active=true starting pos=3174
[junit4:junit4] 2> 20273 T161 C5 P54360 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 20275 T161 C5 P54360 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a),segFN=segments_2,generation=2,filenames=[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, segments_2, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a),segFN=segments_3,generation=3,filenames=[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4] 2> 20275 T161 C5 P54360 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4] 2> 20276 T161 C5 P54360 oass.SolrIndexSearcher.<init> Opening Searcher@f9fd0b main
[junit4:junit4] 2> 20276 T161 C5 P54360 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 20278 T152 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f9fd0b main{StandardDirectoryReader(segments_2:4:nrt _0(5.0):C54/24)}
[junit4:junit4] 2> 20279 T161 C5 P54360 oasu.UpdateLog$LogReplayer.run WARNING Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=3174}
[junit4:junit4] 2> 20279 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 20279 T153 C5 P54360 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 20279 T153 C5 P54360 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20284 T153 C5 P54360 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 20332 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[10025 (-1428919968958775296)]} 0 0
[junit4:junit4] 2> 20336 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10025 (-1428919968962969600)]} 0 0
[junit4:junit4] 2> 20339 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10033 (1428919968966115328)]} 0 0
[junit4:junit4] 2> 20342 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10033 (1428919968969261056)]} 0 0
[junit4:junit4] 2> 20348 T108 C6 P54339 /update {wt=javabin&version=2} {delete=[25 (-1428919968974503936)]} 0 1
[junit4:junit4] 2> 20351 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[25 (-1428919968977649664)]} 0 1
[junit4:junit4] 2> 20353 T105 C6 P54339 /update {wt=javabin&version=2} {add=[33 (1428919968979746816)]} 0 1
[junit4:junit4] 2> 20358 T127 C7 P54351 /update {wt=javabin&version=2} {add=[33 (1428919968983941120)]} 0 2
[junit4:junit4] 2> 20369 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10034 (1428919968996524032)]} 0 1
[junit4:junit4] 2> 20373 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10034 (1428919969000718336)]} 0 1
[junit4:junit4] 2> 20385 T106 C6 P54339 /update {wt=javabin&version=2} {add=[34 (1428919969013301248)]} 0 1
[junit4:junit4] 2> 20388 T130 C7 P54351 /update {wt=javabin&version=2} {add=[34 (1428919969015398400)]} 0 2
[junit4:junit4] 2> 20454 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[10027 (-1428919969086701568)]} 0 1
[junit4:junit4] 2> 20459 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10027 (-1428919969091944448)]} 0 0
[junit4:junit4] 2> 20465 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10035 (1428919969096138752)]} 0 2
[junit4:junit4] 2> 20468 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[27 (-1428919969101381632)]} 0 0
[junit4:junit4] 2> 20469 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10035 (1428919969101381632)]} 0 2
[junit4:junit4] 2> 20473 T125 C7 P54351 /update {wt=javabin&version=2} {delete=[27 (-1428919969106624512)]} 0 0
[junit4:junit4] 2> 20478 T109 C6 P54339 /update {wt=javabin&version=2} {add=[35 (1428919969110818816)]} 0 1
[junit4:junit4] 2> 20483 T127 C7 P54351 /update {wt=javabin&version=2} {add=[35 (1428919969116061696)]} 0 1
[junit4:junit4] 2> 20519 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10036 (1428919969154859008)]} 0 1
[junit4:junit4] 2> 20524 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10036 (1428919969160101888)]} 0 0
[junit4:junit4] 2> 20533 T106 C6 P54339 /update {wt=javabin&version=2} {add=[36 (1428919969169539072)]} 0 0
[junit4:junit4] 2> 20539 T130 C7 P54351 /update {wt=javabin&version=2} {add=[36 (1428919969174781952)]} 0 1
[junit4:junit4] 2> 20553 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 20555 T115 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:54360_nn_smm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:54360/nn_smm"}
[junit4:junit4] 2> 20566 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[10028 (-1428919969204142080)]} 0 0
[junit4:junit4] 2> 20569 T126 C7 P54351 /update {wt=javabin&version=2} {delete=[10028 (-1428919969207287808)]} 0 0
[junit4:junit4] 2> 20575 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10037 (1428919969212530688)]} 0 1
[junit4:junit4] 2> 20580 T125 C7 P54351 /update {wt=javabin&version=2} {add=[10037 (1428919969218822144)]} 0 0
[junit4:junit4] 2> 20581 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[28 (-1428919969219870720)]} 0 0
[junit4:junit4] 2> 20586 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[28 (-1428919969225113600)]} 0 0
[junit4:junit4] 2> 20591 T109 C6 P54339 /update {wt=javabin&version=2} {add=[37 (1428919969229307904)]} 0 1
[junit4:junit4] 2> 20595 T128 C7 P54351 /update {wt=javabin&version=2} {add=[37 (1428919969233502208)]} 0 1
[junit4:junit4] 2> 20604 T134 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> 20604 T114 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> 20604 T150 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> 20605 T121 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> 20621 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[10033 (-1428919969261813760)]} 0 1
[junit4:junit4] 2> C5_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:54360_nn_smm, base_url=http://127.0.0.1:54360/nn_smm}
[junit4:junit4] 2> 20628 T146 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10033 (-1428919969264959488)]} 0 1
[junit4:junit4] 2> 20629 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10033 (-1428919969264959488)]} 0 5
[junit4:junit4] 2> 20629 T91 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 20630 T91 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 20634 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10038 (1428919969275445248)]} 0 0
[junit4:junit4] 2> 20637 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[33 (-1428919969278590976)]} 0 0
[junit4:junit4] 2> 20640 T91 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@b80f9d
[junit4:junit4] 2> 20646 T142 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[33 (-1428919969281736704)]} 0 2
[junit4:junit4] 2> 20647 T126 C7 P54351 /update {wt=javabin&version=2} {delete=[33 (-1428919969281736704)]} 0 7
[junit4:junit4] 2> 20648 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10038 (1428919969280688128)]} 0 5
[junit4:junit4] 2> 20649 T141 C5 P54360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@b80f9d
[junit4:junit4] 2> 20653 T91 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=2,deletesByQuery=0,errors=0,cumulative_adds=29,cumulative_deletesById=14,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 20654 T141 C5 P54360 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=1,adds=1,deletesById=2,deletesByQuery=0,errors=0,cumulative_adds=29,cumulative_deletesById=14,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 20654 T141 C5 P54360 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 20654 T141 C5 P54360 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 20655 T141 C5 P54360 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 20655 T108 C6 P54339 /update {wt=javabin&version=2} {add=[38 (1428919969297465344)]} 0 1
[junit4:junit4] 2> 20658 T141 C5 P54360 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a),segFN=segments_3,generation=3,filenames=[_0_NestedPulsing_0.doc, _0.fnm, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Memory_0.ram, _0_1.del, _0_Lucene42_0.dvm, _0.nvm, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_Lucene41_0.doc, _0.nvd, _0_SimpleText_0.pst, _0.fdx, _0.si, _0_Lucene41_0.tim, _0.fdt, _0_Lucene41_0.tip, segments_3]
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a),segFN=segments_4,generation=4,filenames=[_2_Lucene41_0.pos, _2_NestedPulsing_0.tim, _2.si, _2_Lucene41_0.tim, _2_SimpleText_0.pst, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _2_Lucene41_0.tip, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_SimpleText_0.pst, _0.nvd, _2_Memory_0.ram, _0.si, _0_Lucene41_0.tim, _2_NestedPulsing_0.tip, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _0.fnm, _0_Memory_0.ram, _2.fdt, _0_1.del, _2_Lucene41_0.doc, _0.nvm, _2.fdx, _2.fnm, _2.nvm, _2_Lucene42_0.dvm, _0_Lucene41_0.doc, _2_NestedPulsing_0.pos, _2.nvd, _0.fdx, _0.fdt, _2_NestedPulsing_0.doc, _2_Lucene42_0.dvd, segments_4]
[junit4:junit4] 2> 20658 T141 C5 P54360 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_2_Lucene41_0.pos, _2_NestedPulsing_0.tim, _2.si, _2_Lucene41_0.tim, _2_SimpleText_0.pst, _0_Lucene42_0.dvd, _0_Lucene41_0.pos, _0_Lucene42_0.dvm, _2_Lucene41_0.tip, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _0_NestedPulsing_0.pos, _0_SimpleText_0.pst, _0.nvd, _2_Memory_0.ram, _0.si, _0_Lucene41_0.tim, _2_NestedPulsing_0.tip, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _0.fnm, _0_Memory_0.ram, _2.fdt, _0_1.del, _2_Lucene41_0.doc, _0.nvm, _2.fdx, _2.fnm, _2.nvm, _2_Lucene42_0.dvm, _0_Lucene41_0.doc, _2_NestedPulsing_0.pos, _2.nvd, _0.fdx, _0.fdt, _2_NestedPulsing_0.doc, _2_Lucene42_0.dvd, segments_4]
[junit4:junit4] 2> 20662 T141 C5 P54360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 20662 T91 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 20667 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10038 (1428919969280688128)]} 0 29
[junit4:junit4] 2> 20667 T96 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d48b1f3770008
[junit4:junit4] 2> 20668 T141 C5 P54360 oass.SolrIndexSearcher.<init> Opening Searcher@5c4edc main
[junit4:junit4] 2> 20668 T141 C5 P54360 /update {distrib.from=http://127.0.0.1:54351/nn_smm/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {} 0 1
[junit4:junit4] 2> 20668 T134 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> 20669 T141 C5 P54360 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> 20670 T93 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:54368 which had sessionid 0x13d48b1f3770008
[junit4:junit4] 2> 20674 T114 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 20676 T114 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> 20677 T141 C5 P54360 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> 20678 T141 C5 P54360 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@b80f9d
[junit4:junit4] 2> 20679 T141 C5 P54360 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=1,deletesById=2,deletesByQuery=0,errors=0,cumulative_adds=29,cumulative_deletesById=14,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 20679 T141 C5 P54360 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 20679 T134 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 20680 T121 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 20681 T121 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> 20680 T91 oaz.ZooKeeper.close Session: 0x13d48b1f3770008 closed
[junit4:junit4] 2> 20687 T125 C7 P54351 oasc.SolrException.log SEVERE shard update error StdNode: http://127.0.0.1:54360/nn_smm/collection1/:org.apache.solr.common.SolrException: Server at http://127.0.0.1:54360/nn_smm/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> 20694 T125 C7 P54351 oasup.DistributedUpdateProcessor.doFinish try and ask http://127.0.0.1:54360/nn_smm to recover
[junit4:junit4] 2> 20694 T125 C7 P54351 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 20695 T91 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/nn_smm,null}
[junit4:junit4] 2> 20752 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10037 (-1428919969399177216)]} 0 0
[junit4:junit4] 2> 20755 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[10037 (-1428919969402322944)]} 0 0
[junit4:junit4] 2> 20759 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10039 (1428919969405468672)]} 0 1
[junit4:junit4] 2> 20763 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10039 (1428919969409662976)]} 0 1
[junit4:junit4] 2> 20794 T110 C6 P54339 /update {wt=javabin&version=2} {delete=[10038 (-1428919969443217408)]} 0 0
[junit4:junit4] 2> 20797 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10038 (-1428919969446363136)]} 0 0
[junit4:junit4] 2> 20802 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10040 (1428919969451606016)]} 0 1
[junit4:junit4] 2> 20805 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10040 (1428919969454751744)]} 0 0
[junit4:junit4] 2> 20888 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10041 (1428919969540734976)]} 0 1
[junit4:junit4] 2> 20891 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10041 (1428919969543880704)]} 0 1
[junit4:junit4] 2> 20969 T105 C6 P54339 /update {wt=javabin&version=2} {add=[10042 (1428919969625669632)]} 0 1
[junit4:junit4] 2> 20974 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10042 (1428919969631961088)]} 0 0
[junit4:junit4] 2> 21065 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10043 (1428919969727381504)]} 0 1
[junit4:junit4] 2> 21068 T129 C7 P54351 /update {wt=javabin&version=2} {add=[10043 (1428919969730527232)]} 0 0
[junit4:junit4] 2> 21085 T106 C6 P54339 /update {wt=javabin&version=2} {delete=[10043 (-1428919969748353024)]} 0 0
[junit4:junit4] 2> 21092 T126 C7 P54351 /update {wt=javabin&version=2} {delete=[10043 (-1428919969755693056)]} 0 0
[junit4:junit4] 2> 21098 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10044 (1428919969760935936)]} 0 1
[junit4:junit4] 2> 21103 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10044 (1428919969765130240)]} 0 2
[junit4:junit4] 2> 21143 T107 C6 P54339 /update {wt=javabin&version=2} {delete=[10044 (-1428919969809170432)]} 0 0
[junit4:junit4] 2> 21147 T127 C7 P54351 /update {wt=javabin&version=2} {delete=[10044 (-1428919969813364736)]} 0 1
[junit4:junit4] 2> 21151 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10045 (1428919969817559040)]} 0 0
[junit4:junit4] 2> 21155 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10045 (1428919969821753344)]} 0 0
[junit4:junit4] 2> 21201 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10045 (-1428919969869987840)]} 0 0
[junit4:junit4] 2> 21204 T129 C7 P54351 /update {wt=javabin&version=2} {delete=[10045 (-1428919969873133568)]} 0 0
[junit4:junit4] 2> 21207 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10046 (1428919969876279296)]} 0 0
[junit4:junit4] 2> 21210 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10046 (1428919969879425024)]} 0 0
[junit4:junit4] 2> 21266 T110 C6 P54339 /update {wt=javabin&version=2} {add=[10047 (1428919969937096704)]} 0 1
[junit4:junit4] 2> 21271 T130 C7 P54351 /update {wt=javabin&version=2} {add=[10047 (1428919969943388160)]} 0 0
[junit4:junit4] 2> 21325 T107 C6 P54339 /update {wt=javabin&version=2} {add=[10048 (1428919969998962688)]} 0 1
[junit4:junit4] 2> 21330 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10048 (1428919970004205568)]} 0 1
[junit4:junit4] 2> 21403 T108 C6 P54339 /update {wt=javabin&version=2} {add=[10049 (1428919970081800192)]} 0 0
[junit4:junit4] 2> 21406 T128 C7 P54351 /update {wt=javabin&version=2} {add=[10049 (1428919970084945920)]} 0 0
[junit4:junit4] 2> 21490 T109 C6 P54339 /update {wt=javabin&version=2} {add=[10050 (1428919970173026304)]} 0 1
[junit4:junit4] 2> 21492 T126 C7 P54351 /update {wt=javabin&version=2} {add=[10050 (1428919970175123456)]} 0 0
[junit4:junit4] 2> 21549 T105 C6 P54339 /update {wt=javabin&version=2} {delete=[10049 (-1428919970234892288)]} 0 0
[junit4:junit4] 2> 21553 T130 C7 P54351 /update {wt=javabin&version=2} {delete=[10049 (-1428919970239086592)]} 0 0
[junit4:junit4] 2> 21559 T106 C6 P54339 /update {wt=javabin&version=2} {add=[10051 (1428919970244329472)]} 0 1
[junit4:junit4] 2> 21565 T127 C7 P54351 /update {wt=javabin&version=2} {add=[10051 (1428919970250620928)]} 0 2
[junit4:junit4] 2> 21589 T125 C7 P54351 oasup.DistributedUpdateProcessor.doFinish Could not tell a replica to recover org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:54360/nn_smm
[junit4:junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:409)
[junit4:junit4] 2> at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doFinish(DistributedUpdateProcessor.java:440)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.finish(DistributedUpdateProcessor.java:1086)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.finish(LogUpdateProcessorFactory.java:179)
[junit4:junit4] 2> at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:83)
[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$Re
[...truncated too long message...]
2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 42882 T174 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=Lucene41(blocksize=128), text=PostingsFormat(name=SimpleText), _version_=Lucene41(blocksize=128), rnd_b=PostingsFormat(name=NestedPulsing), intDefault=Lucene41(blocksize=128), timestamp=Lucene41(blocksize=128), id=PostingsFormat(name=NestedPulsing), a_t=Lucene41(blocksize=128), range_facet_sl=PostingsFormat(name=SimpleText), range_facet_si=PostingsFormat(name=Memory doPackFST= false), other_tl1=Lucene41(blocksize=128), multiDefault=PostingsFormat(name=Memory doPackFST= false), a_si=PostingsFormat(name=Memory doPackFST= false)}, docValues:{timestamp=DocValuesFormat(name=Lucene42)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=uk, timezone=JST
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_15 (32-bit)/cpus=2,threads=3,free=51630656,total=88875008
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestPostingsSolrHighlighter, UUIDFieldTest, RequestHandlersTest, TestRandomDVFaceting, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, SolrIndexConfigTest, PrimUtilsTest, RecoveryZkTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.seed=D4944D6FF9E99B4C -Dtests.slow=true -Dtests.locale=uk -Dtests.timezone=JST -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=151, name=coreLoadExecutor-45-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@91c2c lockFactory=org.apache.lucene.store.NativeFSLockFactory@f3d86c)
[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=153, 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@b0e731 lockFactory=org.apache.lucene.store.NativeFSLockFactory@f79d9a)
[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 44.10s, 1 test, 2 errors <<< FAILURES!
[...truncated 819 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: 60 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Description set: Java: 32bit/jdk1.7.0_15 -client -XX:+UseSerialGC
Email was triggered for: Failure
Sending email for trigger: Failure