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/05/24 05:29:19 UTC

[JENKINS] Lucene-Solr-4.x-Linux (32bit/ibm-j9-jdk7) - Build # 5740 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/5740/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

3 tests failed.
REGRESSION:  org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch

Error Message:
Server at http://127.0.0.1:47124/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:47124/onenodecollectioncore returned non ok status:404, message:Can not find: /onenodecollectioncore/update
	at __randomizedtesting.SeedInfo.seed([A6844CCE21EDDCF3:2762C2D656B2BCCF]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
	at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
	at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:198)
	at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:90)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)


REGRESSION:  org.apache.solr.handler.TestReplicationHandler.doTestStressReplication

Error Message:
timed out waiting for collection1 startAt time to exceed: Fri May 24 14:09:09 SBT 2013

Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Fri May 24 14:09:09 SBT 2013
	at __randomizedtesting.SeedInfo.seed([A6844CCE21EDDCF3:7D2F4C0824C5B540]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1473)
	at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:777)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)


REGRESSION:  org.apache.solr.update.AutoCommitTest.testCommitWithin

Error Message:
Exception during query

Stack Trace:
java.lang.RuntimeException: Exception during query
	at __randomizedtesting.SeedInfo.seed([A6844CCE21EDDCF3:1C5623B6A2C332E6]:0)
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:525)
	at org.apache.solr.update.AutoCommitTest.testCommitWithin(AutoCommitTest.java:298)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:613)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:780)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
	xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">2222</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><int name="intDefault">42</int><date name="timestamp">2013-05-24T03:12:31.882Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
</response>

	request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
	at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:518)
	... 41 more




Build Log:
[...truncated 9568 lines...]
[junit4:junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4:junit4]   2> 129349 T856 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
[junit4:junit4]   2> 129352 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 129359 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40173
[junit4:junit4]   2> 129360 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 129360 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 129361 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master
[junit4:junit4]   2> 129361 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/solr.xml
[junit4:junit4]   2> 129362 T856 oasc.CoreContainer.<init> New CoreContainer 1901481940
[junit4:junit4]   2> 129363 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 129363 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/'
[junit4:junit4]   2> 129364 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/'
[junit4:junit4]   2> 129399 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 129400 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 129400 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 129401 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 129401 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 129402 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 129402 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 129403 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 129404 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 129404 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 129410 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 129413 T866 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1
[junit4:junit4]   2> 129413 T866 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/'
[junit4:junit4]   2> 129441 T866 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 129466 T866 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 129466 T866 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 129469 T866 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 129478 T866 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 129479 T866 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 129479 T866 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/
[junit4:junit4]   2> 129479 T866 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 129480 T866 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 129480 T866 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data
[junit4:junit4]   2> 129481 T866 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index/
[junit4:junit4]   2> 129481 T866 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 129482 T866 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index
[junit4:junit4]   2> 129482 T866 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_1,generation=1}
[junit4:junit4]   2> 129483 T866 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 129484 T866 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 129484 T866 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 129484 T866 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 129485 T866 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 129485 T866 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 129485 T866 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 129487 T866 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 129488 T866 oass.SolrIndexSearcher.<init> Opening Searcher@c2d48ece main
[junit4:junit4]   2> 129489 T866 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 129489 T866 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 129489 T866 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4]   2> 129490 T866 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 129490 T866 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 129490 T867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c2d48ece main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 129491 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 129492 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 129492 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 129500 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 129505 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38241
[junit4:junit4]   2> 129505 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 129506 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 129507 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave
[junit4:junit4]   2> 129507 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/solr.xml
[junit4:junit4]   2> 129508 T856 oasc.CoreContainer.<init> New CoreContainer 536853045
[junit4:junit4]   2> 129508 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 129509 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/'
[junit4:junit4]   2> 129509 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/'
[junit4:junit4]   2> 129545 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 129545 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 129546 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 129547 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 129547 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 129548 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 129548 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 129549 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 129549 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 129550 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 129555 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 129558 T878 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1
[junit4:junit4]   2> 129558 T878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/'
[junit4:junit4]   2> 129579 T878 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 129604 T878 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 129605 T878 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 129608 T878 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 129617 T878 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 129618 T878 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 129618 T878 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/
[junit4:junit4]   2> 129618 T878 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 129618 T878 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 129619 T878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data
[junit4:junit4]   2> 129620 T878 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index/
[junit4:junit4]   2> 129620 T878 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 129620 T878 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index
[junit4:junit4]   2> 129621 T878 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_1,generation=1}
[junit4:junit4]   2> 129622 T878 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 129623 T878 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 129623 T878 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 129623 T878 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 129623 T878 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 129624 T878 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 129624 T878 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 129625 T878 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 129627 T878 oass.SolrIndexSearcher.<init> Opening Searcher@9abdb2a1 main
[junit4:junit4]   2> 129627 T878 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 129628 T878 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 129628 T878 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4]   2> 129635 T878 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4:junit4]   2> 129635 T878 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 129635 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9abdb2a1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 129636 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 129636 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 129637 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C343 name=collection1 org.apache.solr.core.SolrCore@8b716014
[junit4:junit4]   2> 129647 T862 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 129822 T863 C343 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_1,generation=1}
[junit4:junit4]   2> 129823 T863 C343 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 129824 T863 C343 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 174
[junit4:junit4]   2> 129826 T862 C343 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 129831 T862 C343 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_2,generation=2}
[junit4:junit4]   2> 129831 T862 C343 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 129832 T862 C343 oass.SolrIndexSearcher.<init> Opening Searcher@64fcd8e9 main
[junit4:junit4]   2> 129833 T862 C343 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 129833 T867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64fcd8e9 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   2> 129834 T862 C343 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin} {commit=} 0 8
[junit4:junit4]   2> 129840 T882 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 129840 T882 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 129842 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 129843 T882 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 129843 T882 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 129844 T882 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 129847 T863 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 129848 T882 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4:junit4]   2> 129849 T882 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904003
[junit4:junit4]   2> 129850 T882 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@795dfcc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b1bd0407) fullCopy=false
[junit4:junit4]   2> 129854 T865 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 129858 T862 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129861 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129865 T863 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129868 T865 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129872 T862 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129875 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129878 T863 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129881 T865 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129885 T862 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 129886 T882 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 129910 T882 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 129911 T882 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 130145 T882 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_2,generation=2}
[junit4:junit4]   2> 130145 T882 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 130146 T882 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 130147 T882 oass.SolrIndexSearcher.<init> Opening Searcher@76617e83 main
[junit4:junit4]   2> 130147 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76617e83 main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   2> 130148 T882 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904003 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904003;done=true>>]
[junit4:junit4]   2> 130148 T882 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904003
[junit4:junit4]   2> 130148 T882 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904003
[junit4:junit4]   2> ASYNC  NEW_CORE C344 name=collection1 org.apache.solr.core.SolrCore@13388e38
[junit4:junit4]   2> 130149 T874 C344 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:40173/solr/replication} status=0 QTime=310 
[junit4:junit4]   2> 130153 T877 C344 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:empty1&version=2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 130156 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130159 T863 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130165 T865 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&slave=false&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130166 T875 C344 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=4 
[junit4:junit4]   2> 130169 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130172 T874 C344 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130174 T863 C343 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 130175 T863 C343 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_3,generation=3}
[junit4:junit4]   2> 130176 T863 C343 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 130177 T863 C343 oass.SolrIndexSearcher.<init> Opening Searcher@879e0d4f main
[junit4:junit4]   2> 130178 T863 C343 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 130178 T867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@879e0d4f main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):C1)}
[junit4:junit4]   2> 130179 T863 C343 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin} {commit=} 0 5
[junit4:junit4]   2> 130181 T885 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 130181 T885 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 130184 T862 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130184 T885 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4:junit4]   2> 130185 T885 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4:junit4]   2> 130185 T885 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 130187 T865 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=3&command=filelist&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130188 T885 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4:junit4]   2> 130189 T885 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904343
[junit4:junit4]   2> 130190 T885 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@a41ad0f6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@fc00174a) fullCopy=false
[junit4:junit4]   2> 130190 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4]   2> 130190 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4]   2> 130190 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130191 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130191 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130191 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4]   2> 130193 T864 C343 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=segments_3&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130194 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4]   2> 130195 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4]   2> 130195 T885 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4]   2> 130195 T885 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 130196 T885 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 130197 T885 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 130197 T885 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 130198 T885 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_3,generation=3}
[junit4:junit4]   2> 130198 T885 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 130199 T885 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 130199 T885 oass.SolrIndexSearcher.<init> Opening Searcher@770d3d5d main
[junit4:junit4]   2> 130200 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@770d3d5d main{StandardDirectoryReader(segments_3:3:nrt _0(4.4):C1)}
[junit4:junit4]   2> 130200 T885 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904343 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904343;done=true>>]
[junit4:junit4]   2> 130200 T885 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904343
[junit4:junit4]   2> 130201 T885 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904343
[junit4:junit4]   2> 130201 T876 C344 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:40173/solr/replication} status=0 QTime=20 
[junit4:junit4]   2> 130205 T863 C343 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 1
[junit4:junit4]   2> 130207 T862 C343 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> ASYNC  NEW_CORE C345 name=collection1 org.apache.solr.core.SolrCore@8b716014
[junit4:junit4]   2> 130217 T862 C345 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_4,generation=4}
[junit4:junit4]   2> 130218 T862 C345 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4]   2> 130269 T862 C345 oass.SolrIndexSearcher.<init> Opening Searcher@c560150b main
[junit4:junit4]   2> 130270 T862 C345 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 130270 T867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c560150b main{StandardDirectoryReader(segments_4:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   2> 130271 T862 C345 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin} {commit=} 0 64
[junit4:junit4]   2> 130274 T887 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 130274 T887 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 130276 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130277 T887 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4]   2> 130277 T887 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4:junit4]   2> 130277 T887 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 130280 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=4&command=filelist&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130281 T887 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4:junit4]   2> 130282 T887 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904435
[junit4:junit4]   2> 130282 T887 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@f7bbe08a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a25a611b) fullCopy=false
[junit4:junit4]   2> 130286 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130288 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130290 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130294 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130299 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=segments_4&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130301 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4]   2> 130304 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130309 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130310 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130310 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4]   2> 130310 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4]   2> 130313 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 130316 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130317 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130317 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4]   2> 130317 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4]   2> 130319 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130320 T887 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4]   2> 130323 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130324 T887 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 130325 T887 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 130326 T887 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 130326 T887 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 130327 T887 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_4,generation=4}
[junit4:junit4]   2> 130328 T887 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4]   2> 130328 T887 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 130329 T887 oass.SolrIndexSearcher.<init> Opening Searcher@3e9a7246 main
[junit4:junit4]   2> 130329 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e9a7246 main{StandardDirectoryReader(segments_4:5:nrt _0(4.4):C1 _1(4.4):C1)}
[junit4:junit4]   2> 130330 T887 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904435 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904435;done=true>>]
[junit4:junit4]   2> 130330 T887 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904435
[junit4:junit4]   2> 130330 T887 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904435
[junit4:junit4]   2> ASYNC  NEW_CORE C346 name=collection1 org.apache.solr.core.SolrCore@13388e38
[junit4:junit4]   2> 130331 T877 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:40173/solr/replication} status=0 QTime=58 
[junit4:junit4]   2> 130334 T875 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:empty2&version=2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 130337 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130340 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130347 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&slave=false&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130349 T876 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=6 
[junit4:junit4]   2> 130355 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130360 T877 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130365 T864 C345 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 1
[junit4:junit4]   2> 130368 T863 C345 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 130373 T863 C345 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_5,generation=5}
[junit4:junit4]   2> 130374 T863 C345 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4]   2> 130426 T863 C345 oass.SolrIndexSearcher.<init> Opening Searcher@fb00291d realtime
[junit4:junit4]   2> 130427 T863 C345 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 130428 T863 C345 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin&openSearcher=false} {commit=} 0 60
[junit4:junit4]   2> 130431 T889 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 130431 T889 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 130433 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130434 T889 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4:junit4]   2> 130435 T889 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4:junit4]   2> 130435 T889 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 130437 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=5&command=filelist&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130438 T889 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4:junit4]   2> 130439 T889 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904593
[junit4:junit4]   2> 130439 T889 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@958bbf63 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7cb293d7) fullCopy=false
[junit4:junit4]   2> 130442 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130443 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130443 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130444 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130444 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4:junit4]   2> 130446 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=segments_5&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130447 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4]   2> 130447 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4:junit4]   2> 130450 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130453 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130455 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130455 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4]   2> 130455 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4]   2> 130455 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130458 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130459 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4:junit4]   2> 130459 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4:junit4]   2> 130461 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130465 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.fnm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130466 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130469 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130470 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4]   2> 130470 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4]   2> 130471 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4:junit4]   2> 130473 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130474 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4]   2> 130475 T889 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4:junit4]   2> 130477 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=5&command=filecontent&file=_2.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130478 T889 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 130480 T889 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 130480 T889 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 130480 T889 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 130482 T889 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_5,generation=5}
[junit4:junit4]   2> 130483 T889 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4]   2> 130483 T889 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 130484 T889 oass.SolrIndexSearcher.<init> Opening Searcher@73a84928 main
[junit4:junit4]   2> 130485 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73a84928 main{StandardDirectoryReader(segments_5:7:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1)}
[junit4:junit4]   2> 130485 T889 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904593 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904593;done=true>>]
[junit4:junit4]   2> 130486 T889 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904593
[junit4:junit4]   2> 130486 T889 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904593
[junit4:junit4]   2> 130486 T874 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:40173/solr/replication} status=0 QTime=56 
[junit4:junit4]   2> 130490 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:empty3&version=2&wt=javabin&sort=id+desc} hits=0 status=0 QTime=1 
[junit4:junit4]   2> 130493 T875 C346 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:empty3&version=2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=0 
[junit4:junit4]   2> 130497 T865 C345 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 1
[junit4:junit4]   2> 130500 T864 C345 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 130504 T864 C345 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=5
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_5,generation=5}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@22090081 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f66f1852),segFN=segments_6,generation=6}
[junit4:junit4]   2> 130504 T864 C345 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4:junit4]   2> 130505 T864 C345 oass.SolrIndexSearcher.<init> Opening Searcher@6428fd7d main
[junit4:junit4]   2> 130506 T864 C345 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 130506 T867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6428fd7d main{StandardDirectoryReader(segments_6:9:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1 _3(4.4):C1)}
[junit4:junit4]   2> 130507 T864 C345 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin} {commit=} 0 7
[junit4:junit4]   2> 130509 T891 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 130510 T891 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 130512 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130512 T891 oash.SnapPuller.fetchLatestIndex Master's generation: 6
[junit4:junit4]   2> 130513 T891 oash.SnapPuller.fetchLatestIndex Slave's generation: 5
[junit4:junit4]   2> 130513 T891 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 130516 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=6&command=filelist&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130518 T891 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 37
[junit4:junit4]   2> 130519 T891 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904673
[junit4:junit4]   2> 130520 T891 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@bebe626b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@8755d455) fullCopy=false
[junit4:junit4]   2> 130520 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130521 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130522 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130522 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4:junit4]   2> 130523 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130523 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130524 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130524 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4:junit4]   2> 130525 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4:junit4]   2> 130525 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4:junit4]   2> 130526 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
[junit4:junit4]   2> 130529 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130531 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4:junit4]   2> 130532 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4:junit4]   2> 130532 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
[junit4:junit4]   2> 130535 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130540 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130543 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4:junit4]   2> 130546 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130549 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130553 T864 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=segments_6&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130554 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4:junit4]   2> 130554 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4:junit4]   2> 130555 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvd because it already exists
[junit4:junit4]   2> 130557 T863 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130561 T862 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130562 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.tim because it already exists
[junit4:junit4]   2> 130562 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4:junit4]   2> 130562 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4:junit4]   2> 130563 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.tip because it already exists
[junit4:junit4]   2> 130563 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4:junit4]   2> 130563 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4:junit4]   2> 130563 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvm because it already exists
[junit4:junit4]   2> 130564 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
[junit4:junit4]   2> 130566 T865 C345 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.fnm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C347 name=collection1 org.apache.solr.core.SolrCore@8b716014
[junit4:junit4]   2> 130586 T863 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=6&command=filecontent&file=_3.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 130588 T891 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4:junit4]   2> 130588 T891 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 130589 T891 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 130589 T891 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 130590 T891 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 130643 T891 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_5,generation=5}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e88b952b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@b2d54206),segFN=segments_6,generation=6}
[junit4:junit4]   2> 130644 T891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 6
[junit4:junit4]   2> 130645 T891 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 130647 T891 oass.SolrIndexSearcher.<init> Opening Searcher@7de8668e main
[junit4:junit4]   2> 130647 T879 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7de8668e main{StandardDirectoryReader(segments_6:9:nrt _0(4.4):C1 _1(4.4):C1 _2(4.4):C1 _3(4.4):C1)}
[junit4:junit4]   2> 130648 T891 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904673 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904673;done=true>>]
[junit4:junit4]   2> 130648 T891 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904673
[junit4:junit4]   2> 130648 T891 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index.20130524140904673
[junit4:junit4]   2> ASYNC  NEW_CORE C348 name=collection1 org.apache.solr.core.SolrCore@13388e38
[junit4:junit4]   2> 130649 T876 C348 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:40173/solr/replication} status=0 QTime=140 
[junit4:junit4]   2> 130653 T862 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&version=2&wt=javabin&sort=id+desc} hits=4 status=0 QTime=1 
[junit4:junit4]   2> 130657 T874 C348 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&version=2&wt=javabin&sort=id+desc} hits=4 status=0 QTime=1 
[junit4:junit4]   2> 130660 T864 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130663 T865 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130669 T863 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&slave=false&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 130670 T875 C348 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=4 
[junit4:junit4]   2> 130673 T862 C347 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130676 T876 C348 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 130677 T856 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4:junit4]   2> 130698 T856 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1901481940
[junit4:junit4]   2> 130699 T856 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@8b716014
[junit4:junit4]   2> 130700 T856 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=4,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 130700 T856 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 130701 T856 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 130702 T856 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 130703 T856 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 130703 T856 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 130704 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data;done=false>>]
[junit4:junit4]   2> 130705 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data
[junit4:junit4]   2> 130705 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index;done=false>>]
[junit4:junit4]   2> 130706 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943504/master/collection1/data/index
[junit4:junit4]   2> 130707 T856 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 130779 T856 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=536853045
[junit4:junit4]   2> 130780 T856 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@13388e38
[junit4:junit4]   2> 130782 T856 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 130784 T856 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 130785 T856 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 130786 T856 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 130788 T856 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 130789 T856 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 130791 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data;done=false>>]
[junit4:junit4]   2> 130792 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data
[junit4:junit4]   2> 130793 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index;done=false>>]
[junit4:junit4]   2> 130795 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364943652/slave/collection1/data/index
[junit4:junit4]   2> 130796 T856 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 130862 T856 oas.SolrTestCaseJ4.setUp ###Starting doTestStressReplication
[junit4:junit4]   2> 130866 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 130870 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55346
[junit4:junit4]   2> 130871 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 130872 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 130872 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master
[junit4:junit4]   2> 130873 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/solr.xml
[junit4:junit4]   2> 130874 T856 oasc.CoreContainer.<init> New CoreContainer -326721421
[junit4:junit4]   2> 130874 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 130875 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/'
[junit4:junit4]   2> 130875 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/'
[junit4:junit4]   2> 130910 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 130911 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 130911 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 130912 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 130913 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 130913 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 130914 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 130914 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 130915 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 130915 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 130920 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 130923 T902 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1
[junit4:junit4]   2> 130923 T902 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/'
[junit4:junit4]   2> 130946 T902 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 130972 T902 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 130973 T902 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 130975 T902 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 130984 T902 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 130985 T902 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 130986 T902 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/
[junit4:junit4]   2> 130986 T902 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 130986 T902 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 130987 T902 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data
[junit4:junit4]   2> 130987 T902 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index/
[junit4:junit4]   2> 130988 T902 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 130988 T902 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index
[junit4:junit4]   2> 130989 T902 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@98019623 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f4ab914b),segFN=segments_1,generation=1}
[junit4:junit4]   2> 130989 T902 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 130990 T902 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 130991 T902 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 130991 T902 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 130991 T902 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 130991 T902 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 130992 T902 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 130993 T902 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 130995 T902 oass.SolrIndexSearcher.<init> Opening Searcher@76aea631 main
[junit4:junit4]   2> 130995 T902 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 130996 T902 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 130996 T902 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4:junit4]   2> 130997 T902 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 130997 T903 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76aea631 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 130997 T902 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 130998 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 130999 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 130999 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 131006 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 131012 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44482
[junit4:junit4]   2> 131013 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 131013 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 131014 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave
[junit4:junit4]   2> 131014 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/solr.xml
[junit4:junit4]   2> 131015 T856 oasc.CoreContainer.<init> New CoreContainer 504226546
[junit4:junit4]   2> 131015 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 131016 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/'
[junit4:junit4]   2> 131016 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/'
[junit4:junit4]   2> 131050 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 131051 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 131052 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 131052 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 131053 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 131053 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 131054 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 131054 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 131055 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 131056 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 131060 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 131063 T914 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1
[junit4:junit4]   2> 131063 T914 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/'
[junit4:junit4]   2> 131084 T914 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 131109 T914 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 131110 T914 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 131112 T914 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 131122 T914 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 131122 T914 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131123 T914 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/
[junit4:junit4]   2> 131123 T914 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 131123 T914 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131124 T914 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data
[junit4:junit4]   2> 131124 T914 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index/
[junit4:junit4]   2> 131125 T914 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 131125 T914 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index
[junit4:junit4]   2> 131126 T914 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fc8a69cb lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15a49633),segFN=segments_1,generation=1}
[junit4:junit4]   2> 131126 T914 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 131127 T914 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 131128 T914 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 131128 T914 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 131128 T914 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 131129 T914 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 131129 T914 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 131130 T914 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 131132 T914 oass.SolrIndexSearcher.<init> Opening Searcher@9ca22913 main
[junit4:junit4]   2> 131133 T914 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 131133 T914 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 131134 T914 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4:junit4]   2> 131134 T914 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 131134 T915 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9ca22913 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 131135 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 131135 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 131136 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 131168 T856 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=504226546
[junit4:junit4]   2> 131169 T856 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3b3a369e
[junit4:junit4]   2> 131170 T856 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 131171 T856 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 131171 T856 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 131172 T856 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 131173 T856 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 131173 T856 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 131174 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data;done=false>>]
[junit4:junit4]   2> 131174 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data
[junit4:junit4]   2> 131175 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index;done=false>>]
[junit4:junit4]   2> 131176 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index
[junit4:junit4]   2> 131176 T856 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 131230 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 131234 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44032
[junit4:junit4]   2> 131235 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 131235 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 131236 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave
[junit4:junit4]   2> 131237 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/solr.xml
[junit4:junit4]   2> 131237 T856 oasc.CoreContainer.<init> New CoreContainer -2067041336
[junit4:junit4]   2> 131238 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 131239 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/'
[junit4:junit4]   2> 131239 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/'
[junit4:junit4]   2> 131274 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 131275 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 131275 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 131276 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 131277 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 131277 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 131278 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 131278 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 131279 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 131280 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 131285 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 131287 T927 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1
[junit4:junit4]   2> 131288 T927 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/'
[junit4:junit4]   2> 131314 T927 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 131339 T927 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 131339 T927 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 131342 T927 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 131351 T927 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 131352 T927 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131352 T927 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/
[junit4:junit4]   2> 131352 T927 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 131353 T927 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131353 T927 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data
[junit4:junit4]   2> 131354 T927 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index/
[junit4:junit4]   2> 131354 T927 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 131355 T927 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index
[junit4:junit4]   2> 131355 T927 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8),segFN=segments_1,generation=1}
[junit4:junit4]   2> 131356 T927 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 131357 T927 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 131357 T927 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 131357 T927 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 131358 T927 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 131358 T927 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 131358 T927 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 131359 T927 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 131361 T927 oass.SolrIndexSearcher.<init> Opening Searcher@14a00d6a main
[junit4:junit4]   2> 131362 T927 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 131362 T927 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 131362 T927 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 131363 T928 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14a00d6a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 131363 T927 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 131364 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 131364 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 131365 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 131392 T856 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=-326721421
[junit4:junit4]   2> 131393 T856 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@c5ae50f0
[junit4:junit4]   2> 131394 T856 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 131394 T856 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 131395 T856 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 131395 T856 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 131396 T856 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 131397 T856 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 131397 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index;done=false>>]
[junit4:junit4]   2> 131398 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index
[junit4:junit4]   2> 131399 T856 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data;done=false>>]
[junit4:junit4]   2> 131399 T856 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data
[junit4:junit4]   2> 131400 T856 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4]   2> 131454 T856 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 131460 T856 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51041
[junit4:junit4]   2> 131461 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 131462 T856 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 131462 T856 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master
[junit4:junit4]   2> 131463 T856 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/solr.xml
[junit4:junit4]   2> 131464 T856 oasc.CoreContainer.<init> New CoreContainer 1452615796
[junit4:junit4]   2> 131465 T856 oasc.CoreContainer$Initializer.initialize no solr.xml found. using default old-style solr.xml
[junit4:junit4]   2> 131466 T856 oasc.CoreContainer.load Loading CoreContainer using Solr Home: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/'
[junit4:junit4]   2> 131467 T856 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/'
[junit4:junit4]   2> 131510 T856 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 131511 T856 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 131511 T856 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 131512 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 131512 T856 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 131513 T856 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 131514 T856 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 131514 T856 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 131515 T856 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 131515 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 131521 T856 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 131523 T939 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1
[junit4:junit4]   2> 131524 T939 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/'
[junit4:junit4]   2> 131550 T939 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 131574 T939 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 131575 T939 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 131577 T939 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 131586 T939 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 131587 T939 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131587 T939 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/
[junit4:junit4]   2> 131588 T939 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 131588 T939 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 131589 T939 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data
[junit4:junit4]   2> 131589 T939 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index/
[junit4:junit4]   2> 131589 T939 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 131590 T939 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945017/master/collection1/data/index
[junit4:junit4]   2> 131590 T939 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_1,generation=1}
[junit4:junit4]   2> 131591 T939 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 131591 T939 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 131592 T939 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 131592 T939 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 131592 T939 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 131593 T939 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 131593 T939 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 131594 T939 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 131596 T939 oass.SolrIndexSearcher.<init> Opening Searcher@9b388b74 main
[junit4:junit4]   2> 131596 T939 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 131597 T939 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 131597 T939 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4:junit4]   2> 131598 T939 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_1,generation=1}
[junit4:junit4]   2> 131598 T939 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 131598 T939 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 131599 T939 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 131599 T940 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@9b388b74 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 131599 T856 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4]   2> 131600 T856 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 131601 T856 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C349 name=collection1 org.apache.solr.core.SolrCore@a1d84a7b
[junit4:junit4]   2> 131614 T935 C349 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 131615 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 1
[junit4:junit4]   2> ASYNC  NEW_CORE C350 name=collection1 org.apache.solr.core.SolrCore@1ffefc6b
[junit4:junit4]   2> 131622 T923 C350 oasu.DirectUpdateHandler2.deleteAll [collection1] REMOVING ALL DOCUMENTS FROM INDEX
[junit4:junit4]   2> 131624 T923 C350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8),segFN=segments_1,generation=1}
[junit4:junit4]   2> 131624 T923 C350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 131626 T923 C350 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {deleteByQuery=*:*} 0 4
[junit4:junit4]   2> 131629 T924 C350 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 131630 T924 C350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8),segFN=segments_2,generation=2}
[junit4:junit4]   2> 131630 T924 C350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 131631 T924 C350 oass.SolrIndexSearcher.<init> Opening Searcher@34d00fb4 main
[junit4:junit4]   2> 131631 T924 C350 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 131631 T928 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34d00fb4 main{StandardDirectoryReader(segments_2:2:nrt)}
[junit4:junit4]   2> 131632 T924 C350 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 3
[junit4:junit4]   2> 131636 T936 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[0]} 0 0
[junit4:junit4]   2> 131639 T937 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 0
[junit4:junit4]   2> 131642 T938 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 0
[junit4:junit4]   2> 131645 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 0
[junit4:junit4]   2> 131648 T936 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 0
[junit4:junit4]   2> 131651 T937 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[5]} 0 0
[junit4:junit4]   2> 131653 T938 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[6]} 0 0
[junit4:junit4]   2> 131656 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[7]} 0 0
[junit4:junit4]   2> 131661 T936 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[8]} 0 2
[junit4:junit4]   2> 131664 T937 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[9]} 0 0
[junit4:junit4]   2> 131667 T938 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[10]} 0 0
[junit4:junit4]   2> 131670 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[11]} 0 0
[junit4:junit4]   2> 131673 T936 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[12]} 0 0
[junit4:junit4]   2> 131676 T937 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[13]} 0 1
[junit4:junit4]   2> 131678 T938 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[14]} 0 0
[junit4:junit4]   2> 131681 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[15]} 0 0
[junit4:junit4]   2> 131686 T936 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[16]} 0 2
[junit4:junit4]   2> 131689 T937 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[17]} 0 0
[junit4:junit4]   2> 131692 T938 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[18]} 0 0
[junit4:junit4]   2> 131695 T935 C349 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 131698 T935 C349 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_2,generation=2}
[junit4:junit4]   2> 131699 T935 C349 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 131700 T935 C349 oass.SolrIndexSearcher.<init> Opening Searcher@418622cd main
[junit4:junit4]   2> 131700 T935 C349 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 131701 T940 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@418622cd main{StandardDirectoryReader(segments_2:4:nrt _0(4.4):C19)}
[junit4:junit4]   2> 131701 T935 C349 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 7
[junit4:junit4]   2> 131704 T936 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=19 status=0 QTime=0 
[junit4:junit4]   2> 131708 T923 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> 131711 T942 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 131711 T942 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 131713 T938 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 131714 T942 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 131715 T942 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4:junit4]   2> 131715 T942 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 131719 T935 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=2&command=filelist&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 131721 T942 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4:junit4]   2> 131722 T942 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876
[junit4:junit4]   2> 131722 T942 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a) fullCopy=true
[junit4:junit4]   2> 131726 T936 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 131730 T937 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131734 T938 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131738 T935 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131743 T936 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131746 T937 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=segments_2&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131750 T938 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131753 T935 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131757 T936 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 131761 T937 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=2&command=filecontent&file=_0.nvd&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 131762 T942 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 131762 T942 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{size=1634, checksum=1505963717, name=schema.xml}]
[junit4:junit4]   2> 131767 T938 C349 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&cf=schema.xml&qt=/replication&generation=2&command=filecontent&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 131771 T942 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130524140905876
[junit4:junit4]   2> 131776 T942 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8)
[junit4:junit4]   2> 131777 T942 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4]   2> 131778 T942 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@e6f212c4 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e9536de8)
[junit4:junit4]   2> 131778 T944 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1
[junit4:junit4]   2> 131778 T942 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 131779 T944 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/'
[junit4:junit4]   2> 131779 T942 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 131780 T942 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 131780 T942 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index/ new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876
[junit4:junit4]   2> 131781 T942 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a),segFN=segments_2,generation=2}
[junit4:junit4]   2> 131781 T942 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 131782 T942 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 131782 T942 oass.SolrIndexSearcher.<init> Opening Searcher@abc4d17c main
[junit4:junit4]   2> 131783 T928 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@abc4d17c main{StandardDirectoryReader(segments_2:4:nrt _0(4.4):C19)}
[junit4:junit4]   2> ASYNC  NEW_CORE C351 name=collection1 org.apache.solr.core.SolrCore@1ffefc6b
[junit4:junit4]   2> 131783 T924 C351 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:51041/solr/replication} status=0 QTime=72 
[junit4:junit4]   2> 131784 T924 C351 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index;done=true>>]
[junit4:junit4]   2> 131785 T924 C351 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index
[junit4:junit4]   2> 131785 T924 C351 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index
[junit4:junit4]   2> 131787 T925 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=1 
[junit4:junit4]   2> 131802 T944 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 131835 T944 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 131835 T944 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 131838 T944 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 131851 T944 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 131852 T944 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/
[junit4:junit4]   2> 131852 T944 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 131853 T944 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876
[junit4:junit4]   2> 131858 T944 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 131859 T944 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 131859 T944 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 131859 T944 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 131860 T944 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 131860 T944 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 131861 T944 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 131864 T944 oass.SolrIndexSearcher.<init> Opening Searcher@6124ef57 main
[junit4:junit4]   2> 131865 T944 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 131865 T944 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 131866 T944 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 131866 T944 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 131866 T944 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 131866 T944 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 131867 T945 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6124ef57 main{StandardDirectoryReader(segments_2:4:nrt _0(4.4):C19)}
[junit4:junit4]   2> 131867 T944 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a),segFN=segments_2,generation=2}
[junit4:junit4]   2> 131868 T944 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 131868 T944 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 131869 T944 oass.SolrIndexSearcher.<init> Opening Searcher@1e3a30e0 main
[junit4:junit4]   2> 131870 T944 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4]   2> 131870 T944 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1ffefc6b
[junit4:junit4]   2> 131870 T944 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 131870 T945 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e3a30e0 main{StandardDirectoryReader(segments_2:4:nrt _0(4.4):C19)}
[junit4:junit4]   2> 131871 T944 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 131990 T926 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C352 name=collection1 org.apache.solr.core.SolrCore@ae7d50ce
[junit4:junit4]   2> 131999 T923 C352 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=19 status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C353 name=collection1 org.apache.solr.core.SolrCore@a1d84a7b
[junit4:junit4]   2> 132003 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132007 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 132010 T924 C352 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132013 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132016 T925 C352 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132020 T926 C352 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[19]} 0 1
[junit4:junit4]   2> 132023 T923 C352 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[20]} 0 0
[junit4:junit4]   2> 132026 T924 C352 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[21]} 0 0
[junit4:junit4]   2> 132029 T925 C352 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 132034 T925 C352 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a),segFN=segments_3,generation=3}
[junit4:junit4]   2> 132035 T925 C352 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 132036 T925 C352 oass.SolrIndexSearcher.<init> Opening Searcher@6f26df34 main
[junit4:junit4]   2> 132037 T925 C352 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 132037 T945 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f26df34 main{StandardDirectoryReader(segments_3:6:nrt _0(4.4):C19 _1(4.4):C3)}
[junit4:junit4]   2> 132038 T925 C352 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 9
[junit4:junit4]   2> 132042 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[22]} 0 0
[junit4:junit4]   2> 132045 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[23]} 0 0
[junit4:junit4]   2> 132047 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[24]} 0 0
[junit4:junit4]   2> 132050 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[25]} 0 0
[junit4:junit4]   2> 132053 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[26]} 0 0
[junit4:junit4]   2> 132056 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[27]} 0 1
[junit4:junit4]   2> 132058 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[28]} 0 0
[junit4:junit4]   2> 132062 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[29]} 0 0
[junit4:junit4]   2> 132068 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[30]} 0 3
[junit4:junit4]   2> 132072 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[31]} 0 1
[junit4:junit4]   2> 132075 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[32]} 0 0
[junit4:junit4]   2> 132078 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[33]} 0 0
[junit4:junit4]   2> 132082 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[34]} 0 0
[junit4:junit4]   2> 132085 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[35]} 0 0
[junit4:junit4]   2> 132089 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[36]} 0 1
[junit4:junit4]   2> 132093 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[37]} 0 1
[junit4:junit4]   2> 132098 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[38]} 0 3
[junit4:junit4]   2> 132101 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[39]} 0 0
[junit4:junit4]   2> 132104 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[40]} 0 0
[junit4:junit4]   2> 132108 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[41]} 0 1
[junit4:junit4]   2> 132112 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[42]} 0 0
[junit4:junit4]   2> 132115 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[43]} 0 0
[junit4:junit4]   2> 132118 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[44]} 0 0
[junit4:junit4]   2> 132121 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[45]} 0 0
[junit4:junit4]   2> 132125 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[46]} 0 1
[junit4:junit4]   2> 132129 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[47]} 0 0
[junit4:junit4]   2> 132132 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[48]} 0 0
[junit4:junit4]   2> 132135 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[49]} 0 0
[junit4:junit4]   2> 132139 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[50]} 0 0
[junit4:junit4]   2> 132143 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[51]} 0 0
[junit4:junit4]   2> 132147 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[52]} 0 0
[junit4:junit4]   2> 132150 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[53]} 0 0
[junit4:junit4]   2> 132155 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[54]} 0 0
[junit4:junit4]   2> 132160 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[55]} 0 1
[junit4:junit4]   2> 132164 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[56]} 0 0
[junit4:junit4]   2> 132167 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[57]} 0 0
[junit4:junit4]   2> 132170 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[58]} 0 0
[junit4:junit4]   2> 132174 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[59]} 0 0
[junit4:junit4]   2> 132178 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[60]} 0 0
[junit4:junit4]   2> 132182 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[61]} 0 0
[junit4:junit4]   2> 132186 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[62]} 0 1
[junit4:junit4]   2> 132189 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[63]} 0 0
[junit4:junit4]   2> 132194 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[64]} 0 1
[junit4:junit4]   2> 132198 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[65]} 0 0
[junit4:junit4]   2> 132202 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[66]} 0 0
[junit4:junit4]   2> 132206 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[67]} 0 0
[junit4:junit4]   2> 132210 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[68]} 0 0
[junit4:junit4]   2> 132214 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[69]} 0 1
[junit4:junit4]   2> 132218 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[70]} 0 1
[junit4:junit4]   2> 132222 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[71]} 0 1
[junit4:junit4]   2> 132226 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[72]} 0 0
[junit4:junit4]   2> 132231 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[73]} 0 1
[junit4:junit4]   2> 132236 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[74]} 0 0
[junit4:junit4]   2> 132240 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[75]} 0 0
[junit4:junit4]   2> 132244 T936 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[76]} 0 0
[junit4:junit4]   2> 132248 T935 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[77]} 0 1
[junit4:junit4]   2> 132256 T938 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[78]} 0 4
[junit4:junit4]   2> 132265 T937 C353 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 132268 T937 C353 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_3,generation=3}
[junit4:junit4]   2> 132268 T937 C353 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 132271 T937 C353 oass.SolrIndexSearcher.<init> Opening Searcher@f8c92899 main
[junit4:junit4]   2> 132271 T937 C353 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 132272 T940 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f8c92899 main{StandardDirectoryReader(segments_3:6:nrt _0(4.4):C19 _1(4.4):C57)}
[junit4:junit4]   2> 132273 T937 C353 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 8
[junit4:junit4]   2> 132281 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=76 status=0 QTime=3 
[junit4:junit4]   2> 132286 T924 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> 132289 T946 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 132290 T946 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 132293 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132294 T946 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4:junit4]   2> 132294 T946 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4:junit4]   2> 132295 T946 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 132299 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=3&command=filelist&wt=javabin} status=0 QTime=2 
[junit4:junit4]   2> 132304 T946 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4:junit4]   2> 132313 T946 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461
[junit4:junit4]   2> 132313 T946 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329) fullCopy=true
[junit4:junit4]   2> 132321 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1_Lucene41_0.tim&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 132331 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132356 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132366 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.si&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 132369 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=segments_3&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132373 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132377 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132381 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132385 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132398 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132405 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 132411 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 132417 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132423 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132429 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132435 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132442 T937 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132448 T936 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_0.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132454 T935 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=3&command=filecontent&file=_1.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132458 T946 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 132459 T946 oash.SnapPuller.downloadConfFiles Starting download of configuration files from master: [{size=1508, checksum=265618607, name=schema.xml}]
[junit4:junit4]   2> 132463 T938 C353 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&cf=schema.xml&qt=/replication&generation=3&command=filecontent&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 132538 T946 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130524140906461
[junit4:junit4]   2> 132539 T946 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a)
[junit4:junit4]   2> 132540 T946 oash.SnapPuller.fetchLatestIndex Configuration files are modified, core will be reloaded
[junit4:junit4]   2> 132541 T946 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@4971464b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9ab9f44a)
[junit4:junit4]   2> 132541 T946 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 132542 T946 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 132542 T946 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 132541 T948 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1
[junit4:junit4]   2> 132544 T948 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/'
[junit4:junit4]   2> 132546 T946 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876 new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461
[junit4:junit4]   2> 132548 T946 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329),segFN=segments_3,generation=3}
[junit4:junit4]   2> 132549 T946 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 132550 T946 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 132565 T946 oass.SolrIndexSearcher.<init> Opening Searcher@93c5aeb5 main
[junit4:junit4]   2> 132566 T945 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@93c5aeb5 main{StandardDirectoryReader(segments_3:6:nrt _0(4.4):C19 _1(4.4):C57)}
[junit4:junit4]   2> ASYNC  NEW_CORE C354 name=collection1 org.apache.solr.core.SolrCore@ae7d50ce
[junit4:junit4]   2> 132567 T925 C354 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:51041/solr/replication} status=0 QTime=278 
[junit4:junit4]   2> 132568 T925 C354 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876;done=true>>]
[junit4:junit4]   2> 132569 T925 C354 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876
[junit4:junit4]   2> 132570 T925 C354 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140905876
[junit4:junit4]   2> 132571 T926 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> 132653 T948 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 132693 T948 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 132696 T948 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 132707 T948 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 132718 T948 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 132719 T948 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/, dataDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/
[junit4:junit4]   2> 132720 T948 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4:junit4]   2> 132720 T948 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461
[junit4:junit4]   2> 132721 T948 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 132721 T948 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 132721 T948 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 132722 T948 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 132722 T948 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 132722 T948 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 132724 T948 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 132726 T948 oass.SolrIndexSearcher.<init> Opening Searcher@4bd622c2 main
[junit4:junit4]   2> 132726 T948 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 132727 T948 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 132727 T948 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 132727 T948 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 132728 T949 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4bd622c2 main{StandardDirectoryReader(segments_3:6:nrt _0(4.4):C19 _1(4.4):C57)}
[junit4:junit4]   2> 132728 T948 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 132728 T948 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 132730 T948 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329),segFN=segments_3,generation=3}
[junit4:junit4]   2> 132730 T948 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4]   2> 132730 T948 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 132732 T948 oass.SolrIndexSearcher.<init> Opening Searcher@45c3384b main
[junit4:junit4]   2> 132732 T948 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4]   2> 132732 T948 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@ae7d50ce
[junit4:junit4]   2> 132733 T948 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 132733 T949 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@45c3384b main{StandardDirectoryReader(segments_3:6:nrt _0(4.4):C19 _1(4.4):C57)}
[junit4:junit4]   2> 132734 T948 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 132774 T924 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C355 name=collection1 org.apache.solr.core.SolrCore@202ba576
[junit4:junit4]   2> 132784 T923 C355 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=76 status=0 QTime=2 
[junit4:junit4]   2> ASYNC  NEW_CORE C356 name=collection1 org.apache.solr.core.SolrCore@a1d84a7b
[junit4:junit4]   2> 132789 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 132792 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132796 T925 C355 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132800 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132804 T926 C355 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132809 T924 C355 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[79]} 0 1
[junit4:junit4]   2> 132813 T923 C355 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[80]} 0 0
[junit4:junit4]   2> 132819 T925 C355 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[81]} 0 0
[junit4:junit4]   2> 132822 T926 C355 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 132825 T926 C355 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329),segFN=segments_4,generation=4}
[junit4:junit4]   2> 132825 T926 C355 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4]   2> 132827 T926 C355 oass.SolrIndexSearcher.<init> Opening Searcher@40353e51 main
[junit4:junit4]   2> 132828 T926 C355 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 132828 T949 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@40353e51 main{StandardDirectoryReader(segments_4:8:nrt _0(4.4):C19 _1(4.4):C57 _2(4.4):C3)}
[junit4:junit4]   2> 132829 T926 C355 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 7
[junit4:junit4]   2> 132833 T937 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[82]} 0 1
[junit4:junit4]   2> 132837 T936 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[83]} 0 1
[junit4:junit4]   2> 132841 T935 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[84]} 0 1
[junit4:junit4]   2> 132845 T938 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[85]} 0 1
[junit4:junit4]   2> 132849 T937 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[86]} 0 1
[junit4:junit4]   2> 132852 T936 C356 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 132856 T936 C356 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_2,generation=2}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_3,generation=3}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@90f5ea9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@585012f2),segFN=segments_4,generation=4}
[junit4:junit4]   2> 132857 T936 C356 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4]   2> 132858 T936 C356 oass.SolrIndexSearcher.<init> Opening Searcher@3e5c9b11 main
[junit4:junit4]   2> 132859 T936 C356 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 132859 T940 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e5c9b11 main{StandardDirectoryReader(segments_4:8:nrt _0(4.4):C19 _1(4.4):C57 _2(4.4):C5)}
[junit4:junit4]   2> 132861 T936 C356 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={softCommit=false&commit=true&version=2&waitSearcher=true&wt=javabin} {commit=} 0 9
[junit4:junit4]   2> 132867 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=81 status=0 QTime=1 
[junit4:junit4]   2> 132872 T924 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={action=status&version=2&wt=javabin&core=collection1} status=0 QTime=0 
[junit4:junit4]   2> 132879 T950 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4:junit4]   2> 132880 T950 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 132899 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 132904 T950 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4:junit4]   2> 132904 T950 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4:junit4]   2> 132910 T950 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 132915 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&generation=4&command=filelist&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 132917 T950 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4:junit4]   2> 132918 T950 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140907072
[junit4:junit4]   2> 132919 T950 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@fd4b443f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@408b3cf4) fullCopy=true
[junit4:junit4]   2> 132931 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132939 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132943 T937 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0_Lucene41_0.doc&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132946 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 132950 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133006 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=segments_4&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 133013 T937 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133020 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133026 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.nvd&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133033 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133042 T937 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1_Lucene41_0.doc&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 133047 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.fnm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133063 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133067 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0_Lucene41_0.tim&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133071 T937 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133080 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.nvm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133091 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fnm&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133113 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.nvm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 133128 T937 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.fnm&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 133134 T935 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0_Lucene41_0.tip&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133142 T936 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133151 T938 C356 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.si&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> ASYNC  NEW_CORE C357 name=collection1 org.apache.solr.core.SolrCore@a1d84a7b
[junit4:junit4]   2> 133249 T937 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133266 T935 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133270 T936 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.fdt&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133274 T937 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_0.fdx&wt=filestream} status=0 QTime=1 
[junit4:junit4]   2> 133277 T935 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_1.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133280 T938 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&qt=/replication&generation=4&command=filecontent&file=_2.fdx&wt=filestream} status=0 QTime=0 
[junit4:junit4]   2> 133281 T950 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 133282 T950 oash.SnapPuller.modifyIndexProps New index installed. Updating index properties... index=index.20130524140907072
[junit4:junit4]   2> 133284 T950 oash.SnapPuller.fetchLatestIndex removing old index directory MockDirWrapper(org.apache.lucene.store.RAMDirectory@403c58f7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20237329)
[junit4:junit4]   2> 133284 T950 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 133285 T950 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 133285 T950 oasu.DefaultSolrCoreState.newIndexWriter Rollback old IndexWriter... core=collection1
[junit4:junit4]   2> 133286 T950 oasc.SolrCore.getNewIndexDir New index directory detected: old=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461 new=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140907072
[junit4:junit4]   2> 133287 T950 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fd4b443f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@408b3cf4),segFN=segments_4,generation=4}
[junit4:junit4]   2> 133288 T950 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4]   2> 133288 T950 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 133290 T950 oass.SolrIndexSearcher.<init> Opening Searcher@61a46b32 main
[junit4:junit4]   2> 133291 T949 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61a46b32 main{StandardDirectoryReader(segments_4:8:nrt _0(4.4):C19 _1(4.4):C57 _2(4.4):C5)}
[junit4:junit4]   2> ASYNC  NEW_CORE C358 name=collection1 org.apache.solr.core.SolrCore@202ba576
[junit4:junit4]   2> 133291 T926 C358 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={wait=true&command=fetchindex&masterUrl=http://127.0.0.1:51041/solr/replication} status=0 QTime=416 
[junit4:junit4]   2> 133292 T926 C358 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461 [CachedDir<<refCount=0;path=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461;done=true>>]
[junit4:junit4]   2> 133293 T926 C358 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461
[junit4:junit4]   2> 133293 T926 C358 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1369364945158/slave/collection1/data/index.20130524140906461
[junit4:junit4]   2> 133296 T923 C358 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=81 status=0 QTime=2 
[junit4:junit4]   2> 133300 T936 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=1 
[junit4:junit4]   2> 133303 T937 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 133308 T935 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&slave=false&version=2&command=details&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 133310 T924 C358 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=getDetails&version=2&command=details&wt=javabin} status=0 QTime=4 
[junit4:junit4]   2> 133313 T936 C357 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 133317 T925 C358 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&_trace=assertVersions&version=2&command=indexversion&wt=javabin} status=0 QTime=0 
[junit4:junit4]   2> 133321 T926 C358 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[87]} 0 1
[junit4:junit4]   2> 133324 T923 C358 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[88]} 0 0
[junit4:junit4]   2> 133327 T924 C358 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[89]} 0 0
[junit4:junit4]   2> 133330 T925 C358 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 133333 T925 C358 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fd4b443f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@408b3cf4),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fd4b443f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@408b3cf4),segFN=segments_5,generation=5}
[junit4:junit4]   2> 133334 T925 C358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4

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

> 344277 T1748 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommit maxTime=1000ms,soft autocommits=3,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=14,adds=1,deletesById=0,deletesByQuery=1,errors=0,cumulative_adds=14,cumulative_deletesById=1,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4]   2> 344278 T1748 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 344280 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[0]} 0 1
[junit4:junit4]   2> 344280 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[1]} 0 1
[junit4:junit4]   2> 344281 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[2]} 0 1
[junit4:junit4]   2> 344282 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[3]} 0 1
[junit4:junit4]   2> 344282 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[4]} 0 1
[junit4:junit4]   2> 344283 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[5]} 0 1
[junit4:junit4]   2> 344284 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[6]} 0 1
[junit4:junit4]   2> 344285 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[7]} 0 1
[junit4:junit4]   2> 344285 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[8]} 0 1
[junit4:junit4]   2> 344288 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[9]} 0 1
[junit4:junit4]   2> 344289 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[10]} 0 1
[junit4:junit4]   2> 344290 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[11]} 0 1
[junit4:junit4]   2> 344291 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[12]} 0 1
[junit4:junit4]   2> 344291 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[13]} 0 1
[junit4:junit4]   2> ASYNC  NEW_CORE C776 name=collection1 org.apache.solr.core.SolrCore@a6697429
[junit4:junit4]   2> 344292 T1748 C776 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:1&start=0&qt=standard&version=2.2&rows=20} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 344294 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[14]} 0 1
[junit4:junit4]   2> 344295 T1755 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4]   2> 344302 T1755 oass.SolrIndexSearcher.<init> Opening Searcher@ea137cc9 main
[junit4:junit4]   2> 344303 T1755 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 344305 T1754 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ea137cc9 main{StandardDirectoryReader(segments_4:22:nrt _6(4.4):C10 _7(4.4):C5)}
[junit4:junit4]   2> 344545 T1748 oasup.LogUpdateProcessor.finish [collection1] {add=[15]} 0 1
[junit4:junit4]   2> 344547 T1748 C776 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:14&start=0&qt=standard&version=2.2&rows=20} hits=1 status=0 QTime=1 
[junit4:junit4]   2> 344550 T1748 C776 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=id:15&start=0&qt=standard&version=2.2&rows=20} hits=0 status=0 QTime=0 
[junit4:junit4]   2> 344552 T1748 oas.SolrTestCaseJ4.tearDown ###Ending testMaxDocs
[junit4:junit4]   2> 344556 T1748 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 344557 T1748 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1295156141
[junit4:junit4]   2> 344558 T1748 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@a6697429
[junit4:junit4]   2> 344570 T1748 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommit maxDocs=14,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=16,adds=1,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=16,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 344571 T1748 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 344571 T1748 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 344571 T1748 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 344574 T1748 C776 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3a8999a lockFactory=org.apache.lucene.store.NativeFSLockFactory@29cac8ce)),segFN=segments_4,generation=4}
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3a8999a lockFactory=org.apache.lucene.store.NativeFSLockFactory@29cac8ce)),segFN=segments_5,generation=5}
[junit4:junit4]   2> 344574 T1748 C776 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4]   2> 344575 T1748 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 344575 T1748 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 344576 T1748 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424;done=false>>]
[junit4:junit4]   2> 344576 T1748 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424
[junit4:junit4]   2> 344577 T1748 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424/index;done=false>>]
[junit4:junit4]   2> 344577 T1748 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-AutoCommitTest-1369365149424/index
[junit4:junit4]   2> NOTE: test params are: codec=Lucene42: {range_facet_si=PostingsFormat(name=Direct), range_facet_l=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=MockSep), range_facet_sl=MockVariableIntBlock(baseBlockSize=14), timestamp=PostingsFormat(name=Direct), multiDefault=PostingsFormat(name=Direct), id=MockVariableIntBlock(baseBlockSize=14), subject=PostingsFormat(name=Direct), text=Pulsing41(freqCutoff=18 minBlockSize=3 maxBlockSize=86), field_t=MockVariableIntBlock(baseBlockSize=14)}, docValues:{}, sim=DefaultSimilarity, locale=fi, timezone=America/Yellowknife
[junit4:junit4]   2> NOTE: Linux 3.2.0-41-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=1,free=54481872,total=133169152
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SoftAutoCommitTest, SOLR749Test, TestFunctionQuery, IndexSchemaTest, MoreLikeThisHandlerTest, TestFieldResource, TestCoreContainer, LoggingHandlerTest, BadCopyFieldTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrQueryParser, CoreAdminHandlerTest, QueryParsingTest, ResourceLoaderTest, TestSurroundQueryParser, TestIBSimilarityFactory, PluginInfoTest, TestQuerySenderListener, TestSolrQueryParserResource, TestStressVersions, TestDynamicFieldResource, ZkCLITest, LukeRequestHandlerTest, JsonLoaderTest, ReturnFieldsTest, SchemaVersionSpecificBehaviorTest, SolrTestCaseJ4Test, TestSweetSpotSimilarityFactory, TestQueryUtils, SuggesterFSTTest, TestSerializedLuceneMatchVersion, PrimUtilsTest, BasicFunctionalityTest, SearchHandlerTest, DistributedTermsComponentTest, TestSolrDeletionPolicy2, SolrCoreTest, TestXIncludeConfig, TestPhraseSuggestions, DistributedSpellCheckComponentTest, TestExtendedDismaxParser, DistributedQueryElevationComponentTest, ChaosMonkeyNothingIsSafeTest, TestLFUCache, DirectUpdateHandlerOptimizeTest, ShowFileRequestHandlerTest, TestReplicationHandler, TestRandomDVFaceting, QueryElevationComponentTest, TestFastWriter, TestCharFilters, TestSolrIndexConfig, TestSolrCoreProperties, LegacyHTMLStripCharFilterTest, FieldMutatingUpdateProcessorTest, RegexBoostProcessorTest, DocValuesTest, TestWriterPerf, TestPerFieldSimilarity, FastVectorHighlighterTest, TestFaceting, ResponseLogComponentTest, TestSort, TermsComponentTest, ZkControllerTest, AutoCommitTest]
[junit4:junit4] Completed on J0 in 9.34s, 3 tests, 1 error <<< FAILURES!

[...truncated 508 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:386: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:379: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1243: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:887: There were test failures: 296 suites, 1234 tests, 2 errors, 1 failure, 14 ignored (8 assumptions)

Total time: 44 minutes 42 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure