lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_45) - Build # 8539 - Failure!
Date Mon, 02 Dec 2013 03:01:50 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/8539/
Java: 32bit/jdk1.7.0_45 -server -XX:+UseSerialGC

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

Error Message:
timed out waiting for collection1 startAt time to exceed: Mon Dec 02 15:38:56 NZDT 2013

Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Mon Dec 02 15:38:56 NZDT 2013
	at __randomizedtesting.SeedInfo.seed([83722296B0302664:58D92250B5184FD7]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1515)
	at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:819)
	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:606)
	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:744)




Build Log:
[...truncated 10111 lines...]
   [junit4] Suite: org.apache.solr.handler.TestReplicationHandler
   [junit4]   2> 65611 T314 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
   [junit4]   2> 65617 T314 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 65635 T314 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47052
   [junit4]   2> 65645 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 65645 T314 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 65646 T314 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master
   [junit4]   2> 65646 T314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/'
   [junit4]   2> 65661 T314 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/solr.xml
   [junit4]   2> 65729 T314 oasc.CoreContainer.<init> New CoreContainer 17654045
   [junit4]   2> 65729 T314 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/]
   [junit4]   2> 65730 T314 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 65731 T314 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 65731 T314 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 65731 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 65731 T314 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 65732 T314 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 65732 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 65732 T314 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 65733 T314 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 65737 T314 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 65737 T314 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 65738 T314 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 65741 T324 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1
   [junit4]   2> 65741 T324 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/'
   [junit4]   2> 65781 T324 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 65818 T324 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 65819 T324 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 65823 T324 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 65843 T324 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 65844 T324 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 65844 T324 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/
   [junit4]   2> 65845 T324 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 65845 T324 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data
   [junit4]   2> 65846 T324 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index/
   [junit4]   2> 65846 T324 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 65847 T324 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index
   [junit4]   2> 65847 T324 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 65848 T324 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_1,generation=1}
   [junit4]   2> 65849 T324 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 65850 T324 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 65850 T324 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 65851 T324 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 65851 T324 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 65851 T324 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 65851 T324 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 65851 T324 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 65854 T324 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 65855 T324 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 65856 T324 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 65856 T324 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=10.130859375, floorSegmentMB=1.44140625, forceMergeDeletesPctAllowed=6.231344365408448, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 65857 T324 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_1,generation=1}
   [junit4]   2> 65857 T324 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 65857 T324 oass.SolrIndexSearcher.<init> Opening Searcher@50be48 main
   [junit4]   2> 65858 T324 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 65858 T324 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 65858 T324 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 65859 T314 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 65859 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 65858 T325 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50be48 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 65866 T314 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 65869 T314 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33886
   [junit4]   2> 65870 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 65871 T314 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 65871 T314 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave
   [junit4]   2> 65872 T314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/'
   [junit4]   2> 65890 T314 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/solr.xml
   [junit4]   2> 65937 T314 oasc.CoreContainer.<init> New CoreContainer 29483916
   [junit4]   2> 65938 T314 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/]
   [junit4]   2> 65939 T314 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 65940 T314 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 65940 T314 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 65940 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 65941 T314 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 65941 T314 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 65941 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 65942 T314 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 65942 T314 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 65946 T314 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 65947 T314 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 65947 T314 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 65955 T336 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1
   [junit4]   2> 65956 T336 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/'
   [junit4]   2> 65993 T336 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 66036 T336 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 66037 T336 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 66041 T336 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 66054 T336 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 66055 T336 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 66055 T336 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/
   [junit4]   2> 66055 T336 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 66056 T336 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data
   [junit4]   2> 66056 T336 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index/
   [junit4]   2> 66057 T336 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 66057 T336 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index
   [junit4]   2> 66058 T336 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 66058 T336 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_1,generation=1}
   [junit4]   2> 66059 T336 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 66060 T336 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 66061 T336 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 66061 T336 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 66061 T336 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 66061 T336 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 66062 T336 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 66062 T336 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 66064 T336 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 66066 T336 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 66067 T336 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 66067 T336 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=10.130859375, floorSegmentMB=1.44140625, forceMergeDeletesPctAllowed=6.231344365408448, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 66068 T336 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_1,generation=1}
   [junit4]   2> 66069 T336 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 66069 T336 oass.SolrIndexSearcher.<init> Opening Searcher@91da40 main
   [junit4]   2> 66072 T336 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
   [junit4]   2> 66073 T337 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@91da40 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 66073 T336 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 66075 T314 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 66075 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> ASYNC  NEW_CORE C116 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66085 T322 C116 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> 66090 T320 C116 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 1
   [junit4]   2> 66093 T319 C116 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66096 T319 C116 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_2,generation=2}
   [junit4]   2> 66097 T319 C116 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 66099 T319 C116 oass.SolrIndexSearcher.<init> Opening Searcher@18aada8 main
   [junit4]   2> 66099 T319 C116 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66100 T325 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18aada8 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
   [junit4]   2> 66100 T319 C116 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&commit=true&version=2} {commit=} 0 7
   [junit4]   2> 66112 T340 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 66113 T340 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> ASYNC  NEW_CORE C117 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66116 T321 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66117 T340 oash.SnapPuller.fetchLatestIndex Master's generation: 2
   [junit4]   2> 66117 T340 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
   [junit4]   2> 66117 T340 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 66123 T322 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&wt=javabin&qt=/replication&generation=2&version=2} status=0 QTime=3 
   [junit4]   2> 66124 T340 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
   [junit4]   2> 66125 T340 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847660
   [junit4]   2> 66126 T340 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 66126 T340 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 66127 T340 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 66128 T340 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fa5456 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ceb014) fullCopy=false
   [junit4]   2> 66135 T320 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.doc&qt=/replication&generation=2} status=0 QTime=3 
   [junit4]   2> 66142 T319 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.fdt&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66146 T321 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.nvd&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66151 T322 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.tip&qt=/replication&generation=2} status=0 QTime=1 
   [junit4]   2> 66154 T320 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.fnm&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66158 T319 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=segments_2&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66166 T321 C117 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.fdx&qt=/replication&generation=2} status=0 QTime=1 
   [junit4]   2> ASYNC  NEW_CORE C118 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66175 T322 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.tim&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66180 T320 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.si&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66187 T319 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_0.nvm&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 66188 T340 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 66191 T340 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 66191 T340 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=38.7626953125, floorSegmentMB=1.0439453125, forceMergeDeletesPctAllowed=16.531255834054075, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5535857547742957
   [junit4]   2> 66193 T340 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_2,generation=2}
   [junit4]   2> 66194 T340 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 66194 T340 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 66195 T340 oass.SolrIndexSearcher.<init> Opening Searcher@939dd0 main
   [junit4]   2> 66196 T337 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@939dd0 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
   [junit4]   2> 66196 T340 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847660 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847660;done=true>>]
   [junit4]   2> 66196 T340 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847660
   [junit4]   2> ASYNC  NEW_CORE C119 name=collection1 org.apache.solr.core.SolrCore@134d847
   [junit4]   2> 66197 T332 C119 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:47052/solr/replication} status=0 QTime=84 
   [junit4]   2> 66221 T333 C119 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty1&wt=javabin&version=2} hits=1 status=0 QTime=20 
   [junit4]   2> 66225 T321 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66229 T322 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66236 T320 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&wt=javabin&slave=false&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66237 T334 C119 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=5 
   [junit4]   2> 66241 T319 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66244 T335 C119 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66247 T321 C118 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66249 T321 C118 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 66249 T321 C118 oass.SolrIndexSearcher.<init> Opening Searcher@1ef928a main
   [junit4]   2> 66250 T321 C118 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66250 T325 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ef928a main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):C1)}
   [junit4]   2> 66250 T321 C118 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&commit=true&version=2} {commit=} 0 3
   [junit4]   2> 66252 T342 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 66254 T342 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 66257 T322 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66258 T342 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
   [junit4]   2> 66258 T332 C119 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:47052/solr/replication} status=0 QTime=6 
   [junit4]   2> 66262 T320 C118 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 1
   [junit4]   2> 66265 T319 C118 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66269 T319 C118 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_3,generation=3}
   [junit4]   2> 66270 T319 C118 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 66271 T319 C118 oass.SolrIndexSearcher.<init> Opening Searcher@eac0f main
   [junit4]   2> 66272 T319 C118 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66272 T325 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@eac0f main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C1 _1(5.0):C1)}
   [junit4]   2> 66273 T319 C118 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&commit=true&version=2} {commit=} 0 8
   [junit4]   2> 66275 T343 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 66276 T343 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 66278 T321 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66279 T343 oash.SnapPuller.fetchLatestIndex Master's generation: 3
   [junit4]   2> 66279 T343 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
   [junit4]   2> 66280 T343 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 66282 T322 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&wt=javabin&qt=/replication&generation=3&version=2} status=0 QTime=0 
   [junit4]   2> 66283 T343 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
   [junit4]   2> 66284 T343 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847819
   [junit4]   2> 66284 T343 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 66284 T343 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 66285 T343 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 66285 T343 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@eb8e89 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@a6177c) fullCopy=false
   [junit4]   2> 66288 T320 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.nvd&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66292 T319 C118 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.fdt&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> ASYNC  NEW_CORE C120 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66301 T321 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.fnm&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66302 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
   [junit4]   2> 66303 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
   [junit4]   2> 66306 T322 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.fdx&qt=/replication&generation=3} status=0 QTime=1 
   [junit4]   2> 66310 T320 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.si&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66312 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
   [junit4]   2> 66312 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
   [junit4]   2> 66312 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 66315 T319 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.nvm&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66316 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
   [junit4]   2> 66317 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
   [junit4]   2> 66319 T321 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=segments_3&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66323 T322 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.tim&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66324 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
   [junit4]   2> 66328 T320 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.tip&qt=/replication&generation=3} status=0 QTime=1 
   [junit4]   2> 66331 T319 C120 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_1.doc&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 66337 T343 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
   [junit4]   2> 66337 T343 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 66339 T343 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 66340 T343 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=38.7626953125, floorSegmentMB=1.0439453125, forceMergeDeletesPctAllowed=16.531255834054075, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5535857547742957
   [junit4]   2> 66342 T343 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_3,generation=3}
   [junit4]   2> 66342 T343 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 66342 T343 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 66344 T343 oass.SolrIndexSearcher.<init> Opening Searcher@c2fcd6 main
   [junit4]   2> 66344 T337 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c2fcd6 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C1 _1(5.0):C1)}
   [junit4]   2> 66345 T343 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847819 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847819;done=true>>]
   [junit4]   2> 66345 T343 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847819
   [junit4]   2> ASYNC  NEW_CORE C121 name=collection1 org.apache.solr.core.SolrCore@134d847
   [junit4]   2> 66345 T333 C121 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:47052/solr/replication} status=0 QTime=71 
   [junit4]   2> 66350 T335 C121 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=2 
   [junit4]   2> ASYNC  NEW_CORE C122 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66354 T321 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66357 T322 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66364 T320 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&wt=javabin&slave=false&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66366 T334 C121 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=5 
   [junit4]   2> 66369 T319 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66372 T333 C121 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66377 T321 C122 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 1
   [junit4]   2> 66380 T322 C122 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66384 T322 C122 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_4,generation=4}
   [junit4]   2> 66385 T322 C122 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 66387 T322 C122 oass.SolrIndexSearcher.<init> Opening Searcher@719dbc realtime
   [junit4]   2> 66387 T322 C122 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66388 T322 C122 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&openSearcher=false&commit=true&version=2} {commit=} 0 8
   [junit4]   2> 66390 T345 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 66391 T345 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 66393 T320 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66394 T345 oash.SnapPuller.fetchLatestIndex Master's generation: 4
   [junit4]   2> 66395 T345 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
   [junit4]   2> 66395 T345 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 66398 T319 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&wt=javabin&qt=/replication&generation=4&version=2} status=0 QTime=1 
   [junit4]   2> 66399 T345 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
   [junit4]   2> 66399 T345 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847934
   [junit4]   2> 66400 T345 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 66400 T345 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 66400 T345 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 66400 T345 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@36d7f9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@199c678) fullCopy=false
   [junit4]   2> 66403 T321 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.doc&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66404 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
   [junit4]   2> 66405 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
   [junit4]   2> 66408 T322 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.nvm&qt=/replication&generation=4} status=0 QTime=1 
   [junit4]   2> 66409 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
   [junit4]   2> 66410 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
   [junit4]   2> 66412 T320 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.si&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66413 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 66416 T319 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.tim&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66420 T321 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.fdx&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66421 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
   [junit4]   2> 66421 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
   [junit4]   2> 66424 T322 C122 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.tip&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66430 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
   [junit4]   2> ASYNC  NEW_CORE C123 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66435 T320 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=segments_4&qt=/replication&generation=4} status=0 QTime=1 
   [junit4]   2> 66436 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
   [junit4]   2> 66437 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 66437 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
   [junit4]   2> 66437 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
   [junit4]   2> 66437 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
   [junit4]   2> 66438 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
   [junit4]   2> 66440 T319 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.nvd&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66445 T321 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.fnm&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66447 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tim because it already exists
   [junit4]   2> 66451 T320 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_2.fdt&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 66452 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.doc because it already exists
   [junit4]   2> 66452 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tip because it already exists
   [junit4]   2> 66453 T345 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
   [junit4]   2> 66453 T345 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 66455 T345 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 66456 T345 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=38.7626953125, floorSegmentMB=1.0439453125, forceMergeDeletesPctAllowed=16.531255834054075, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5535857547742957
   [junit4]   2> 66460 T345 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_4,generation=4}
   [junit4]   2> 66460 T345 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 66461 T345 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 66463 T345 oass.SolrIndexSearcher.<init> Opening Searcher@278516 main
   [junit4]   2> 66464 T337 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@278516 main{StandardDirectoryReader(segments_4:7:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1)}
   [junit4]   2> 66464 T345 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847934 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847934;done=true>>]
   [junit4]   2> 66465 T345 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153847934
   [junit4]   2> ASYNC  NEW_CORE C124 name=collection1 org.apache.solr.core.SolrCore@134d847
   [junit4]   2> 66465 T335 C124 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:47052/solr/replication} status=0 QTime=76 
   [junit4]   2> 66469 T319 C123 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> 66474 T332 C124 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=1 status=0 QTime=2 
   [junit4]   2> 66478 T322 C123 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 1
   [junit4]   2> 66481 T320 C123 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 66486 T320 C123 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@603f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@166c5f4),segFN=segments_5,generation=5}
   [junit4]   2> 66487 T320 C123 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 66488 T320 C123 oass.SolrIndexSearcher.<init> Opening Searcher@1231c3c main
   [junit4]   2> 66489 T320 C123 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 66489 T325 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1231c3c main{StandardDirectoryReader(segments_5:9:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1)}
   [junit4]   2> 66489 T320 C123 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&commit=true&version=2} {commit=} 0 8
   [junit4]   2> 66492 T347 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 66493 T347 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 66496 T321 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66498 T347 oash.SnapPuller.fetchLatestIndex Master's generation: 5
   [junit4]   2> 66498 T347 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
   [junit4]   2> 66498 T347 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 66504 T319 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&wt=javabin&qt=/replication&generation=5&version=2} status=0 QTime=1 
   [junit4]   2> 66505 T347 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 37
   [junit4]   2> 66506 T347 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153848040
   [junit4]   2> 66506 T347 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 66506 T347 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 66506 T347 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 66507 T347 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@fb3bbf lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@d957a7) fullCopy=false
   [junit4]   2> 66509 T322 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.nvm&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.doc because it already exists
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvm because it already exists
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
   [junit4]   2> 66511 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
   [junit4]   2> 66514 T320 C123 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.nvd&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66521 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
   [junit4]   2> 66521 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 66521 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.tim because it already exists
   [junit4]   2> 66522 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
   [junit4]   2> ASYNC  NEW_CORE C125 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66525 T321 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.tim&qt=/replication&generation=5} status=0 QTime=1 
   [junit4]   2> 66526 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
   [junit4]   2> 66526 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
   [junit4]   2> 66529 T319 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.fdt&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66531 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.tip because it already exists
   [junit4]   2> 66531 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
   [junit4]   2> 66531 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
   [junit4]   2> 66531 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 66532 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
   [junit4]   2> 66532 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
   [junit4]   2> 66532 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
   [junit4]   2> 66535 T322 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.fnm&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66540 T320 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.doc&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66550 T321 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=segments_5&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66554 T319 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.fdx&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66556 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
   [junit4]   2> 66556 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvd because it already exists
   [junit4]   2> 66556 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
   [junit4]   2> 66556 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tim because it already exists
   [junit4]   2> 66557 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
   [junit4]   2> 66559 T322 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.tip&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66561 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.doc because it already exists
   [junit4]   2> 66562 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tip because it already exists
   [junit4]   2> 66564 T320 C125 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={checksum=true&command=filecontent&wt=filestream&file=_3.si&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 66569 T347 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
   [junit4]   2> 66570 T347 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 66572 T347 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 66573 T347 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=38.7626953125, floorSegmentMB=1.0439453125, forceMergeDeletesPctAllowed=16.531255834054075, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5535857547742957
   [junit4]   2> 66577 T347 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@161ed6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1501f30),segFN=segments_5,generation=5}
   [junit4]   2> 66577 T347 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 66578 T347 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 66581 T347 oass.SolrIndexSearcher.<init> Opening Searcher@51c387 main
   [junit4]   2> 66582 T337 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51c387 main{StandardDirectoryReader(segments_5:9:nrt _0(5.0):C1 _1(5.0):C1 _2(5.0):C1 _3(5.0):C1)}
   [junit4]   2> 66582 T347 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153848040 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153848040;done=true>>]
   [junit4]   2> 66582 T347 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index.20131202153848040
   [junit4]   2> ASYNC  NEW_CORE C126 name=collection1 org.apache.solr.core.SolrCore@134d847
   [junit4]   2> 66583 T333 C126 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:47052/solr/replication} status=0 QTime=91 
   [junit4]   2> ASYNC  NEW_CORE C127 name=collection1 org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66598 T321 C127 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=12 
   [junit4]   2> 66604 T335 C126 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=3 
   [junit4]   2> 66608 T319 C127 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66611 T322 C127 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66618 T320 C127 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&wt=javabin&slave=false&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 66620 T332 C126 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=getDetails&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=6 
   [junit4]   2> 66624 T321 C127 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66627 T334 C126 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={_trace=assertVersions&command=indexversion&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 66628 T314 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
   [junit4]   2> 66650 T314 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=17654045
   [junit4]   2> 66651 T314 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1bb4a02
   [junit4]   2> 66652 T314 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> 66652 T314 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 66653 T314 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 66654 T314 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 66655 T314 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 66655 T314 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 66656 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data;done=false>>]
   [junit4]   2> 66656 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data
   [junit4]   2> 66656 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index;done=false>>]
   [junit4]   2> 66657 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927147/master/collection1/data/index
   [junit4]   2> 66657 T314 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 66731 T314 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=29483916
   [junit4]   2> 66732 T314 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@134d847
   [junit4]   2> 66734 T314 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> 66734 T314 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 66735 T314 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 66735 T314 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 66737 T314 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 66738 T314 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 66738 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index;done=false>>]
   [junit4]   2> 66738 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data/index
   [junit4]   2> 66739 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data;done=false>>]
   [junit4]   2> 66739 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951927396/slave/collection1/data
   [junit4]   2> 66740 T314 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 66801 T314 oas.SolrTestCaseJ4.setUp ###Starting doTestIndexAndConfigReplication
   [junit4]   2> 66806 T314 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 66808 T314 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40680
   [junit4]   2> 66809 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 66809 T314 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 66810 T314 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master
   [junit4]   2> 66810 T314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/'
   [junit4]   2> 66823 T314 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/solr.xml
   [junit4]   2> 66870 T314 oasc.CoreContainer.<init> New CoreContainer 4666107
   [junit4]   2> 66871 T314 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/]
   [junit4]   2> 66872 T314 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 66872 T314 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 66872 T314 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 66873 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 66873 T314 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 66874 T314 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 66874 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 66875 T314 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 66875 T314 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 66881 T314 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 66881 T314 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 66882 T314 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 66885 T358 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1
   [junit4]   2> 66886 T358 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/'
   [junit4]   2> 66931 T358 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 66968 T358 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 66969 T358 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 66978 T358 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 66991 T358 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 66992 T358 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 66993 T358 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/data/
   [junit4]   2> 66993 T358 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 66994 T358 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/data
   [junit4]   2> 66994 T358 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/data/index/
   [junit4]   2> 66994 T358 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 66994 T358 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928337/master/collection1/data/index
   [junit4]   2> 66995 T358 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 66995 T358 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1f43f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1939949),segFN=segments_1,generation=1}
   [junit4]   2> 66996 T358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 66997 T358 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 66998 T358 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 66998 T358 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 66998 T358 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 66999 T358 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 66999 T358 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 66999 T358 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 67003 T358 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 67006 T358 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 67006 T358 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 67007 T358 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=19, maxMergedSegmentMB=10.130859375, floorSegmentMB=1.44140625, forceMergeDeletesPctAllowed=6.231344365408448, segmentsPerTier=43.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 67007 T358 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1f43f1f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1939949),segFN=segments_1,generation=1}
   [junit4]   2> 67008 T358 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 67008 T358 oass.SolrIndexSearcher.<init> Opening Searcher@14d2100 main
   [junit4]   2> 67009 T358 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 67009 T358 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 67009 T358 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 67009 T359 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14d2100 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 67010 T314 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 67010 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 67017 T314 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 67019 T314 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39249
   [junit4]   2> 67020 T314 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 67021 T314 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 67021 T314 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave
   [junit4]   2> 67022 T314 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/'
   [junit4]   2> 67032 T314 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/solr.xml
   [junit4]   2> 67070 T314 oasc.CoreContainer.<init> New CoreContainer 2496265
   [junit4]   2> 67071 T314 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/]
   [junit4]   2> 67075 T314 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 67076 T314 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 67076 T314 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 67076 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 67077 T314 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 67077 T314 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 67078 T314 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 67078 T314 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 67078 T314 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 67082 T314 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 67083 T314 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 67083 T314 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 67087 T370 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1
   [junit4]   2> 67087 T370 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/'
   [junit4]   2> 67122 T370 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 67162 T370 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 67162 T370 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 67168 T370 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 67179 T370 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 67180 T370 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 67180 T370 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/data/
   [junit4]   2> 67180 T370 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 67181 T370 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/data
   [junit4]   2> 67181 T370 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/data/index/
   [junit4]   2> 67181 T370 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 67182 T370 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951928547/slave/collection1/data/index
   [junit4]   2> 67182 T370 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 67184 T370 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@15ab9b2 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1292a3),segFN=segments_1,generation=1}
   [junit4]   2> 67184 T370 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 67185 T370 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 67186 T370 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 67186 T370 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 67186 T370 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 67186 T370 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 67187 T370 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 67187 T370 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 67189 T370 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 67191 T370 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 67191 T370 oasu.CommitTracker.<init> Soft AutoC

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

mergeFactor=40, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 137509 T998 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@a17fe9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c9301c),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@a17fe9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c9301c),segFN=segments_3,generation=3}
   [junit4]   2> 137509 T998 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 137510 T998 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 137511 T998 oass.SolrIndexSearcher.<init> Opening Searcher@1518aa2 main
   [junit4]   2> 137511 T997 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1518aa2 main{StandardDirectoryReader(segments_3:5:nrt _0(5.0):C492 _1(5.0):C1)}
   [junit4]   2> 137511 T998 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index.20131202153959006 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index.20131202153959006;done=true>>]
   [junit4]   2> 137512 T998 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index.20131202153959006
   [junit4]   2> 137611 T994 C272 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=493 status=0 QTime=4 
   [junit4]   2> 137613 T314 oas.SolrTestCaseJ4.tearDown ###Ending doTestStopPoll
   [junit4]   2> 137634 T314 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1473647
   [junit4]   2> 137634 T314 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1713f6
   [junit4]   2> 137634 T314 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=493,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 137635 T314 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 137635 T314 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 137635 T314 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 137636 T314 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 137636 T314 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 137637 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data/index;done=false>>]
   [junit4]   2> 137637 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data/index
   [junit4]   2> 137637 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data;done=false>>]
   [junit4]   2> 137638 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993256/master/collection1/data
   [junit4]   2> 137638 T314 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 137710 T314 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=33232515
   [junit4]   2> 137711 T314 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@d8ec33
   [junit4]   2> 137712 T314 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> 137712 T314 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 137712 T314 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 137713 T314 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 137713 T314 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 137714 T314 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 137714 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data;done=false>>]
   [junit4]   2> 137714 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data
   [junit4]   2> 137715 T314 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index;done=false>>]
   [junit4]   2> 137715 T314 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1385951993410/slave/collection1/data/index
   [junit4]   2> 137716 T314 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 137771 T314 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=es_HN, timezone=Antarctica/McMurdo
   [junit4]   2> NOTE: Linux 3.8.0-33-generic i386/Oracle Corporation 1.7.0_45 (32-bit)/cpus=8,threads=1,free=29643104,total=66703360
   [junit4]   2> NOTE: All tests run in this JVM: [LoggingHandlerTest, BlockCacheTest, TestSurroundQueryParser, DateMathParserTest, AddSchemaFieldsUpdateProcessorFactoryTest, ShardRoutingTest, PolyFieldTest, CSVRequestHandlerTest, TestUniqueKeyFieldResource, AbstractAnalyticsFacetTest, ScriptEngineTest, URLClassifyProcessorTest, SuggesterTest, TestSystemIdResolver, HdfsCollectionsAPIDistributedZkTest, TestReplicationHandler]
   [junit4] Completed on J0 in 72.22s, 14 tests, 1 failure <<< FAILURES!

[...truncated 950 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:420: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:400: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1275: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:908: There were test failures: 357 suites, 1570 tests, 1 failure, 34 ignored (6 assumptions)

Total time: 46 minutes 48 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_45 -server -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message