[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b106) - Build # 7655 - Failure!

[Policeman Jenkins Server <je...@thetaphi.de>]

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7655/
Java: 64bit/jdk1.8.0-ea-b106 -XX:-UseCompressedOops -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.handler.TestReplicationHandler.doTestStressReplication

Error Message:
timed out waiting for collection1 startAt time to exceed: Sat Oct 05 04:35:09 MST 2013

Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Sat Oct 05 04:35:09 MST 2013
	at __randomizedtesting.SeedInfo.seed([36667BF9C995B70:D8CD677999B132C3]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1514)
	at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:818)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:491)
	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:724)




Build Log:
[...truncated 9871 lines...]
   [junit4] Suite: org.apache.solr.handler.TestReplicationHandler
   [junit4]   2> 40560 T377 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
   [junit4]   2> 40567 T377 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 40611 T377 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53273
   [junit4]   2> 40612 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 40612 T377 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 40613 T377 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master
   [junit4]   2> 40613 T377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/'
   [junit4]   2> 40628 T377 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/solr.xml
   [junit4]   2> 40638 T377 oasc.CoreContainer.<init> New CoreContainer 1961837893
   [junit4]   2> 40639 T377 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/]
   [junit4]   2> 40639 T377 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 40639 T377 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 40640 T377 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 40640 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 40640 T377 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 40641 T377 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 40641 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 40641 T377 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 40642 T377 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 40642 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 40644 T377 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 40644 T377 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 40646 T387 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1
   [junit4]   2> 40646 T387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/'
   [junit4]   2> 40686 T387 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 40694 T387 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 40695 T387 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 40698 T387 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 40701 T387 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 40701 T387 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 40701 T387 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/
   [junit4]   2> 40702 T387 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 40702 T387 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data
   [junit4]   2> 40702 T387 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index/
   [junit4]   2> 40702 T387 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 40703 T387 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index
   [junit4]   2> 40703 T387 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=3.1240234375, floorSegmentMB=0.2236328125, forceMergeDeletesPctAllowed=19.346331912134087, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 40704 T387 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_1,generation=1}
   [junit4]   2> 40704 T387 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 40705 T387 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 40705 T387 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 40725 T387 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 40726 T387 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 40726 T387 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 40726 T387 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 40726 T387 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 40727 T387 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 40728 T387 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 40728 T387 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 40729 T387 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.9619140625, floorSegmentMB=2.193359375, forceMergeDeletesPctAllowed=15.509498451725396, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5518207910123221
   [junit4]   2> 40730 T387 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_1,generation=1}
   [junit4]   2> 40730 T387 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 40731 T387 oass.SolrIndexSearcher.<init> Opening Searcher@5c672e46 main
   [junit4]   2> 40733 T387 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 40734 T387 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 40734 T388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c672e46 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 40734 T387 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 40735 T377 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 40735 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 40735 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 40740 T377 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 40749 T377 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40644
   [junit4]   2> 40750 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 40751 T377 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 40751 T377 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave
   [junit4]   2> 40751 T377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/'
   [junit4]   2> 40761 T377 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/solr.xml
   [junit4]   2> 40769 T377 oasc.CoreContainer.<init> New CoreContainer 696740983
   [junit4]   2> 40769 T377 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/]
   [junit4]   2> 40770 T377 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 40770 T377 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 40770 T377 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 40770 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 40770 T377 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 40771 T377 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 40771 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 40771 T377 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 40771 T377 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 40772 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 40773 T377 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 40773 T377 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 40774 T399 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1
   [junit4]   2> 40775 T399 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/'
   [junit4]   2> 40789 T399 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 40796 T399 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 40796 T399 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 40798 T399 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 40801 T399 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 40801 T399 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 40801 T399 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/
   [junit4]   2> 40802 T399 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 40802 T399 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data
   [junit4]   2> 40802 T399 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index/
   [junit4]   2> 40802 T399 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 40803 T399 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index
   [junit4]   2> 40803 T399 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=3.1240234375, floorSegmentMB=0.2236328125, forceMergeDeletesPctAllowed=19.346331912134087, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 40804 T399 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_1,generation=1}
   [junit4]   2> 40804 T399 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 40804 T399 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 40805 T399 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 40806 T399 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 40807 T399 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 40807 T399 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 40807 T399 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.9619140625, floorSegmentMB=2.193359375, forceMergeDeletesPctAllowed=15.509498451725396, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5518207910123221
   [junit4]   2> 40808 T399 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_1,generation=1}
   [junit4]   2> 40808 T399 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 40808 T399 oass.SolrIndexSearcher.<init> Opening Searcher@3c8b0938 main
   [junit4]   2> 40809 T399 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
   [junit4]   2> 40812 T399 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
   [junit4]   2> 40812 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c8b0938 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 40812 T399 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 40813 T377 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 40813 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 40814 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C34 name=collection1 org.apache.solr.core.SolrCore@41fb2f53
   [junit4]   2> 40819 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=2 
   [junit4]   2> 40825 T383 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 2
   [junit4]   2> 40828 T385 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 40841 T385 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_2,generation=2}
   [junit4]   2> 40841 T385 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 40852 T385 C34 oass.SolrIndexSearcher.<init> Opening Searcher@4a446fe3 main
   [junit4]   2> 40852 T385 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 40852 T388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a446fe3 main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):c1)}
   [junit4]   2> 40853 T385 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 25
   [junit4]   2> 40857 T403 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 40858 T403 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 40860 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 40861 T403 oash.SnapPuller.fetchLatestIndex Master's generation: 2
   [junit4]   2> 40861 T403 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
   [junit4]   2> 40861 T403 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 40866 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=3 
   [junit4]   2> 40867 T403 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 4
   [junit4]   2> 40879 T403 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448562
   [junit4]   2> 40879 T403 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@648b11fc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10e2541e) fullCopy=false
   [junit4]   2> 40890 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=2 
   [junit4]   2> 40897 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1 
   [junit4]   2> 40900 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 40904 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 40906 T403 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 40907 T403 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 40907 T403 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 40907 T403 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 40919 T403 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 40919 T403 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 40922 T403 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_2,generation=2}
   [junit4]   2> 40923 T403 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 40923 T403 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 40925 T403 oass.SolrIndexSearcher.<init> Opening Searcher@2e9dc599 main
   [junit4]   2> 40925 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e9dc599 main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):c1)}
   [junit4]   2> 40925 T403 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448562 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448562;done=true>>]
   [junit4]   2> 40926 T403 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448562
   [junit4]   2> ASYNC  NEW_CORE C35 name=collection1 org.apache.solr.core.SolrCore@d37cc39
   [junit4]   2> 40926 T396 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:53273/solr/replication&command=fetchindex&wait=true} status=0 QTime=69 
   [junit4]   2> 40933 T397 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty1&wt=javabin&version=2} hits=1 status=0 QTime=3 
   [junit4]   2> 40941 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
   [junit4]   2> 40944 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 40951 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 40952 T398 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=5 
   [junit4]   2> 40955 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 40957 T392 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 40960 T383 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 40960 T383 C34 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 40961 T383 C34 oass.SolrIndexSearcher.<init> Opening Searcher@6d06a561 main
   [junit4]   2> 40961 T383 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 40961 T388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d06a561 main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):c1)}
   [junit4]   2> 40962 T383 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 2
   [junit4]   2> 40963 T406 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 40964 T406 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 40966 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 40966 T406 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
   [junit4]   2> 40966 T396 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:53273/solr/replication&command=fetchindex&wait=true} status=0 QTime=3 
   [junit4]   2> 40970 T386 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 1
   [junit4]   2> 40973 T379 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 40975 T379 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_3,generation=3}
   [junit4]   2> 40976 T379 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 40977 T379 C34 oass.SolrIndexSearcher.<init> Opening Searcher@18cc9f1 main
   [junit4]   2> 40977 T379 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 40977 T388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18cc9f1 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):c1 _1(4.6):c1)}
   [junit4]   2> 40977 T379 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
   [junit4]   2> 40979 T407 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 40979 T407 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 40981 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 40982 T407 oash.SnapPuller.fetchLatestIndex Master's generation: 3
   [junit4]   2> 40982 T407 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
   [junit4]   2> 40982 T407 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 40985 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=1 
   [junit4]   2> 40986 T407 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 7
   [junit4]   2> 40987 T407 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448680
   [junit4]   2> 40987 T407 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7b402947 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@717d1e45) fullCopy=false
   [junit4]   2> 40987 T407 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 40988 T407 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 40990 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 40998 T407 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 41001 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 41004 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 41007 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 41008 T407 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 41009 T407 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 41009 T407 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 41010 T407 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 41011 T407 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 41011 T407 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 41012 T407 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_3,generation=3}
   [junit4]   2> 41013 T407 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 41013 T407 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 41015 T407 oass.SolrIndexSearcher.<init> Opening Searcher@ac15d49 main
   [junit4]   2> 41015 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ac15d49 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):c1 _1(4.6):c1)}
   [junit4]   2> 41015 T407 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448680 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448680;done=true>>]
   [junit4]   2> 41015 T407 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448680
   [junit4]   2> 41016 T397 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:53273/solr/replication&command=fetchindex&wait=true} status=0 QTime=37 
   [junit4]   2> 41019 T398 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=0 
   [junit4]   2> 41022 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 41024 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41030 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 41031 T392 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=4 
   [junit4]   2> 41033 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41036 T396 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41040 T379 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 1
   [junit4]   2> 41043 T385 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 41045 T385 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_4,generation=4}
   [junit4]   2> 41046 T385 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 41047 T385 C34 oass.SolrIndexSearcher.<init> Opening Searcher@777b2f2d realtime
   [junit4]   2> 41047 T385 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 41047 T385 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2} {commit=} 0 4
   [junit4]   2> 41050 T409 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 41050 T409 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 41052 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 41053 T409 oash.SnapPuller.fetchLatestIndex Master's generation: 4
   [junit4]   2> 41053 T409 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
   [junit4]   2> 41053 T409 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 41056 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=1 
   [junit4]   2> 41057 T409 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
   [junit4]   2> 41058 T409 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448751
   [junit4]   2> 41058 T409 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@218e3113 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1cf203e) fullCopy=false
   [junit4]   2> 41060 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 41062 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 41063 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 41063 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 41063 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 41063 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
   [junit4]   2> 41065 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 41069 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 41072 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 41073 T409 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
   [junit4]   2> 41073 T409 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 41074 T409 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 41074 T409 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 41074 T409 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 41075 T409 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 41075 T409 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 41076 T409 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_4,generation=4}
   [junit4]   2> 41076 T409 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 41076 T409 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 41078 T409 oass.SolrIndexSearcher.<init> Opening Searcher@4af51472 main
   [junit4]   2> 41078 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4af51472 main{StandardDirectoryReader(segments_4:7:nrt _0(4.6):c1 _1(4.6):c1 _2(4.6):c1)}
   [junit4]   2> 41079 T409 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448751 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448751;done=true>>]
   [junit4]   2> 41079 T409 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448751
   [junit4]   2> 41079 T397 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:53273/solr/replication&command=fetchindex&wait=true} status=0 QTime=30 
   [junit4]   2> 41083 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=0 status=0 QTime=1 
   [junit4]   2> 41086 T398 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=1 status=0 QTime=1 
   [junit4]   2> 41090 T385 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 1
   [junit4]   2> 41093 T386 C34 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 41095 T386 C34 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@65a20f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7329d6cd),segFN=segments_5,generation=5}
   [junit4]   2> 41096 T386 C34 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 41097 T386 C34 oass.SolrIndexSearcher.<init> Opening Searcher@6d7e9099 main
   [junit4]   2> 41097 T386 C34 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 41097 T388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d7e9099 main{StandardDirectoryReader(segments_5:9:nrt _0(4.6):c1 _1(4.6):c1 _2(4.6):c1 _3(4.6):c1)}
   [junit4]   2> 41098 T386 C34 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 5
   [junit4]   2> 41100 T411 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 41100 T411 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 41103 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 41104 T411 oash.SnapPuller.fetchLatestIndex Master's generation: 5
   [junit4]   2> 41104 T411 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
   [junit4]   2> 41104 T411 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 41107 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=5&version=2} status=0 QTime=1 
   [junit4]   2> 41107 T411 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 13
   [junit4]   2> 41108 T411 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448802
   [junit4]   2> 41108 T411 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7e851780 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@58a25093) fullCopy=false
   [junit4]   2> 41108 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
   [junit4]   2> 41113 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 41114 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 41114 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfs because it already exists
   [junit4]   2> 41114 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
   [junit4]   2> 41114 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 41115 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 41117 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 41121 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 41124 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_5&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 41125 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 41125 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
   [junit4]   2> 41125 T411 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfe because it already exists
   [junit4]   2> 41125 T411 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 41126 T411 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 41126 T411 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 41126 T411 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 41126 T411 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 41126 T411 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 41128 T411 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@334b9d4b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2111aebd),segFN=segments_5,generation=5}
   [junit4]   2> 41128 T411 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 41128 T411 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 41131 T411 oass.SolrIndexSearcher.<init> Opening Searcher@1bc51320 main
   [junit4]   2> 41131 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1bc51320 main{StandardDirectoryReader(segments_5:9:nrt _0(4.6):c1 _1(4.6):c1 _2(4.6):c1 _3(4.6):c1)}
   [junit4]   2> 41131 T411 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448802 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448802;done=true>>]
   [junit4]   2> 41132 T411 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index.20131005043448802
   [junit4]   2> 41132 T392 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:53273/solr/replication&command=fetchindex&wait=true} status=0 QTime=32 
   [junit4]   2> 41136 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=1 
   [junit4]   2> 41140 T396 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=1 
   [junit4]   2> 41143 T386 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41146 T383 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41152 T379 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41153 T397 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=4 
   [junit4]   2> 41165 T385 C34 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41168 T392 C35 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 41169 T377 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
   [junit4]   2> 41191 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1961837893
   [junit4]   2> 41191 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@41fb2f53
   [junit4]   2> 41192 T377 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]   2> 41192 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 41192 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 41192 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 41193 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 41194 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 41194 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index;done=false>>]
   [junit4]   2> 41194 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data/index
   [junit4]   2> 41195 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data;done=false>>]
   [junit4]   2> 41195 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888255/master/collection1/data
   [junit4]   2> 41195 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 41269 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=696740983
   [junit4]   2> 41270 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@d37cc39
   [junit4]   2> 41270 T377 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]   2> 41271 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 41271 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 41271 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 41272 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 41273 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 41273 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index;done=false>>]
   [junit4]   2> 41274 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data/index
   [junit4]   2> 41274 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data;done=false>>]
   [junit4]   2> 41274 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972888430/slave/collection1/data
   [junit4]   2> 41275 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 41337 T377 oas.SolrTestCaseJ4.setUp ###Starting testNoWriter
   [junit4]   2> 41342 T377 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 41344 T377 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36588
   [junit4]   2> 41345 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 41345 T377 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 41345 T377 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master
   [junit4]   2> 41346 T377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/'
   [junit4]   2> 41359 T377 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/solr.xml
   [junit4]   2> 41384 T377 oasc.CoreContainer.<init> New CoreContainer 869610232
   [junit4]   2> 41384 T377 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/]
   [junit4]   2> 41384 T377 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 41385 T377 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 41385 T377 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 41385 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 41385 T377 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 41385 T377 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 41386 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 41386 T377 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 41386 T377 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 41386 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 41388 T377 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 41388 T377 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 41390 T422 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1
   [junit4]   2> 41390 T422 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/'
   [junit4]   2> 41408 T422 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 41415 T422 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 41416 T422 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 41417 T422 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 41420 T422 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 41421 T422 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 41421 T422 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/
   [junit4]   2> 41421 T422 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 41422 T422 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data
   [junit4]   2> 41422 T422 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index/
   [junit4]   2> 41422 T422 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 41423 T422 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index
   [junit4]   2> 41423 T422 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=3.1240234375, floorSegmentMB=0.2236328125, forceMergeDeletesPctAllowed=19.346331912134087, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 41424 T422 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@15a9819e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d8ea11a),segFN=segments_1,generation=1}
   [junit4]   2> 41424 T422 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 41425 T422 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 41425 T422 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 41426 T422 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 41426 T422 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 41426 T422 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 41426 T422 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 41427 T422 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 41429 T422 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 41430 T422 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 41430 T422 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 41431 T422 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.9619140625, floorSegmentMB=2.193359375, forceMergeDeletesPctAllowed=15.509498451725396, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5518207910123221
   [junit4]   2> 41431 T422 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@15a9819e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6d8ea11a),segFN=segments_1,generation=1}
   [junit4]   2> 41431 T422 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 41432 T422 oass.SolrIndexSearcher.<init> Opening Searcher@470221ae main
   [junit4]   2> 41432 T422 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 41433 T422 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 41433 T423 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@470221ae main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 41433 T422 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 41433 T377 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 41434 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 41434 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 41439 T377 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 41441 T377 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34721
   [junit4]   2> 41442 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 41442 T377 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 41443 T377 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave
   [junit4]   2> 41443 T377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/'
   [junit4]   2> 41453 T377 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/solr.xml
   [junit4]   2> 41462 T377 oasc.CoreContainer.<init> New CoreContainer 1466307816
   [junit4]   2> 41462 T377 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/]
   [junit4]   2> 41463 T377 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 41463 T377 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 41464 T377 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 41464 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 41464 T377 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 41464 T377 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 41465 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 41465 T377 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 41465 T377 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 41466 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 41467 T377 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 41467 T377 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 41469 T434 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1
   [junit4]   2> 41469 T434 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/'
   [junit4]   2> 41486 T434 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 41494 T434 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 41494 T434 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 41497 T434 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 41500 T434 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 41500 T434 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 41500 T434 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/
   [junit4]   2> 41500 T434 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 41501 T434 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data
   [junit4]   2> 41501 T434 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index/
   [junit4]   2> 41501 T434 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 41502 T434 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index
   [junit4]   2> 41502 T434 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=45, maxMergedSegmentMB=3.1240234375, floorSegmentMB=0.2236328125, forceMergeDeletesPctAllowed=19.346331912134087, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 41503 T434 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2b359725 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d28d8b),segFN=segments_1,generation=1}
   [junit4]   2> 41503 T434 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 41503 T434 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 41504 T434 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 41505 T434 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 41506 T434 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 41506 T434 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 41506 T434 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=23.9619140625, floorSegmentMB=2.193359375, forceMergeDeletesPctAllowed=15.509498451725396, segmentsPerTier=15.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5518207910123221
   [junit4]   2> 41506 T434 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2b359725 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d28d8b),segFN=segments_1,generation=1}
   [junit4]   2> 41507 T434 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 41507 T434 oass.SolrIndexSearcher.<init> Opening Searcher@73abf5a4 main
   [junit4]   2> 41507 T434 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
   [junit4]   2> 41507 T435 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73abf5a4 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 41507 T434 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 41508 T377 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 41508 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 41508 T377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 41530 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1466307816
   [junit4]   2> 41531 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3d56919b
   [junit4]   2> 41531 T377 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]   2> 41532 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 41532 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 41532 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 41533 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 41533 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 41533 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data;done=false>>]
   [junit4]   2> 41533 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data
   [junit4]   2> 41534 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index;done=false>>]
   [junit4]   2> 41534 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/collection1/data/index
   [junit4]   2> 41534 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 41607 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=869610232
   [junit4]   2> 41607 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@44ac238c
   [junit4]   2> 41607 T377 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]   2> 41608 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 41608 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 41608 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 41609 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 41609 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 41609 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index;done=false>>]
   [junit4]   2> 41609 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data/index
   [junit4]   2> 41610 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data;done=false>>]
   [junit4]   2> 41610 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889031/master/collection1/data
   [junit4]   2> 41610 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 41662 T377 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 41664 T377 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34721
   [junit4]   2> 41664 T377 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 41665 T377 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 41665 T377 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave
   [junit4]   2> 41665 T377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/'
   [junit4]   2> 41672 T377 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/solr.xml
   [junit4]   2> 41682 T377 oasc.CoreContainer.<init> New CoreContainer 209840608
   [junit4]   2> 41682 T377 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972889129/slave/]
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 41683 T377 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 41684 T377 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 41684 T377 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 41684 T377

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

7483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 103324 T1059 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4881a09e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2d55d65d),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@4881a09e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2d55d65d),segFN=segments_2,generation=2}
   [junit4]   2> 103325 T1059 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 103325 T1059 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 103326 T1059 oass.SolrIndexSearcher.<init> Opening Searcher@7ae4e882 main
   [junit4]   2> 103327 T1058 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ae4e882 main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):c492)}
   [junit4]   2> 103327 T1059 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index.20131005043551005 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index.20131005043551005;done=true>>]
   [junit4]   2> 103327 T1059 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index.20131005043551005
   [junit4]   2> 103408 T1054 C82 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=492 status=0 QTime=1 
   [junit4]   2> 103409 T377 oas.SolrTestCaseJ4.tearDown ###Ending doTestReplicateAfterStartup
   [junit4]   2> 103430 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=271852004
   [junit4]   2> 103431 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6c8e74cd
   [junit4]   2> 103431 T377 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=492,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 103432 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 103432 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 103432 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 103434 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 103434 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 103434 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data/index;done=false>>]
   [junit4]   2> 103435 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data/index
   [junit4]   2> 103435 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data;done=false>>]
   [junit4]   2> 103435 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949257/master/collection1/data
   [junit4]   2> 103436 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 103508 T377 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1858707635
   [junit4]   2> 103508 T377 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@38708c47
   [junit4]   2> 103509 T377 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]   2> 103509 T377 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 103509 T377 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 103510 T377 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 103510 T377 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 103510 T377 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 103511 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index;done=false>>]
   [junit4]   2> 103511 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data/index
   [junit4]   2> 103511 T377 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data;done=false>>]
   [junit4]   2> 103511 T377 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380972949327/slave/collection1/data
   [junit4]   2> 103512 T377 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 103569 T377 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene45: {newname=PostingsFormat(name=Direct), id=PostingsFormat(name=Direct), name=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=es_UY, timezone=America/Creston
   [junit4]   2> NOTE: Linux 3.8.0-31-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=149548176,total=293601280
   [junit4]   2> NOTE: All tests run in this JVM: [TestRemoteStreaming, PeerSyncTest, SearchHandlerTest, TestLRUCache, CacheHeaderTest, TestPostingsSolrHighlighter, TestDocumentBuilder, TestCoreContainer, SchemaVersionSpecificBehaviorTest, FastVectorHighlighterTest, BJQParserTest, AddSchemaFieldsUpdateProcessorFactoryTest, CoreAdminCreateDiscoverTest, TestJmxMonitoredMap, ResponseLogComponentTest, SimpleFacetsTest, MoreLikeThisHandlerTest, ZkCLITest, SpatialFilterTest, SystemInfoHandlerTest, HdfsBasicDistributedZk2Test, TestDocSet, TestValueSourceCache, CSVRequestHandlerTest, TestReplicationHandler]
   [junit4] Completed on J0 in 63.04s, 14 tests, 1 failure <<< FAILURES!

[...truncated 932 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:428: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:408: 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:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 327 suites, 1454 tests, 1 failure, 39 ignored (7 assumptions)

Total time: 35 minutes 10 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b106 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure