[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0-ea-b102) - Build # 3119 - Failure!

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

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3119/
Java: 64bit/jdk1.8.0-ea-b102 -XX:+UseCompressedOops -XX:+UseG1GC

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

Error Message:
timed out waiting for collection1 startAt time to exceed: Mon Aug 26 08:33:09 EAT 2013

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




Build Log:
[...truncated 9654 lines...]
   [junit4] Suite: org.apache.solr.handler.TestReplicationHandler
   [junit4]   2> 170449 T555 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
   [junit4]   2> 170466 T555 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 170483 T555 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52287
   [junit4]   2> 170484 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 170484 T555 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 170484 T555 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master
   [junit4]   2> 170485 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\'
   [junit4]   2> 170519 T555 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\solr.xml
   [junit4]   2> 170521 T555 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\solr.xml does not exist, using default configuration
   [junit4]   2> 170531 T555 oasc.CoreContainer.<init> New CoreContainer 1398472590
   [junit4]   2> 170532 T555 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\]
   [junit4]   2> 170533 T555 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 170533 T555 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 170533 T555 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 170533 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 170534 T555 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 170534 T555 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 170534 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 170534 T555 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 170534 T555 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 170535 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 170546 T567 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1
   [junit4]   2> 170546 T567 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\'
   [junit4]   2> 170579 T567 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 170588 T567 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 170589 T567 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 170593 T567 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 170600 T567 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 170600 T567 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 170601 T567 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\
   [junit4]   2> 170601 T567 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 170601 T567 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\
   [junit4]   2> 170601 T567 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index/
   [junit4]   2> 170601 T567 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 170603 T567 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index
   [junit4]   2> 170604 T567 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=377913605, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 170606 T567 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_1,generation=1}
   [junit4]   2> 170606 T567 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 170607 T567 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 170608 T567 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 170608 T567 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 170609 T567 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 170609 T567 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 170609 T567 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 170609 T567 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 170617 T567 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 170618 T567 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 170618 T567 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 170619 T567 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=5.68359375, floorSegmentMB=1.64453125, forceMergeDeletesPctAllowed=7.994477966024032, segmentsPerTier=49.0, maxCFSSegmentSizeMB=1.431640625, noCFSRatio=0.48405516479428123
   [junit4]   2> 170619 T567 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_1,generation=1}
   [junit4]   2> 170620 T567 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 170620 T567 oass.SolrIndexSearcher.<init> Opening Searcher@669a04a1 main
   [junit4]   2> 170624 T567 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 170624 T567 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 170624 T567 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 170624 T568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@669a04a1 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 170625 T555 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 170625 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 170626 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 170656 T555 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 170661 T555 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52290
   [junit4]   2> 170663 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 170663 T555 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 170663 T555 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave
   [junit4]   2> 170663 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\'
   [junit4]   2> 170682 T555 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\solr.xml
   [junit4]   2> 170683 T555 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\solr.xml does not exist, using default configuration
   [junit4]   2> 170691 T555 oasc.CoreContainer.<init> New CoreContainer 1647837732
   [junit4]   2> 170691 T555 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\]
   [junit4]   2> 170692 T555 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 170692 T555 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 170692 T555 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 170692 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 170692 T555 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 170693 T555 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 170693 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 170693 T555 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 170693 T555 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 170693 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 170701 T581 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1
   [junit4]   2> 170701 T581 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\'
   [junit4]   2> 170736 T581 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 170741 T581 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 170742 T581 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 170747 T581 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 170749 T581 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 170749 T581 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 170750 T581 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\
   [junit4]   2> 170750 T581 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 170750 T581 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\
   [junit4]   2> 170751 T581 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index/
   [junit4]   2> 170751 T581 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 170751 T581 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index
   [junit4]   2> 170752 T581 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=377913605, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 170757 T581 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_1,generation=1}
   [junit4]   2> 170758 T581 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 170758 T581 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 170758 T581 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 170758 T581 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 170758 T581 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 170758 T581 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 170759 T581 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 170759 T581 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 170761 T581 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 170762 T581 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 170762 T581 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 170762 T581 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=5.68359375, floorSegmentMB=1.64453125, forceMergeDeletesPctAllowed=7.994477966024032, segmentsPerTier=49.0, maxCFSSegmentSizeMB=1.431640625, noCFSRatio=0.48405516479428123
   [junit4]   2> 170763 T581 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_1,generation=1}
   [junit4]   2> 170763 T581 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 170763 T581 oass.SolrIndexSearcher.<init> Opening Searcher@155c5ae main
   [junit4]   2> 170768 T581 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
   [junit4]   2> 170768 T581 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 170768 T582 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@155c5ae main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 170769 T555 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 170769 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 170769 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C101 name=collection1 org.apache.solr.core.SolrCore@3ffa0953
   [junit4]   2> 170786 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=8 
   [junit4]   2> 170790 T564 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 0
   [junit4]   2> 170794 T566 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 170801 T566 C101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_2,generation=2}
   [junit4]   2> 170801 T566 C101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 170804 T566 C101 oass.SolrIndexSearcher.<init> Opening Searcher@2faefa3b main
   [junit4]   2> 170804 T566 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 170805 T568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2faefa3b main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):c1)}
   [junit4]   2> 170805 T566 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 11
   [junit4]   2> 170811 T585 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 170811 T585 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 170814 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
   [junit4]   2> 170815 T585 oash.SnapPuller.fetchLatestIndex Master's generation: 2
   [junit4]   2> 170815 T585 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
   [junit4]   2> 170816 T585 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 170828 T561 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=11 
   [junit4]   2> 170829 T585 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 4
   [junit4]   2> 170832 T585 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230794
   [junit4]   2> 170833 T585 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@7ca983b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73406379) fullCopy=false
   [junit4]   2> 170847 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=5 
   [junit4]   2> 170875 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 170881 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 170885 T566 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0 
   [junit4]   2> 170886 T585 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 170888 T585 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 170889 T585 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 170889 T585 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 170890 T585 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 170890 T585 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=41.216796875, floorSegmentMB=1.5283203125, forceMergeDeletesPctAllowed=20.681333853134195, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 170895 T585 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_2,generation=2}
   [junit4]   2> 170895 T585 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 170895 T585 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 170897 T585 oass.SolrIndexSearcher.<init> Opening Searcher@ecb6e51 main
   [junit4]   2> 170900 T582 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ecb6e51 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):c1)}
   [junit4]   2> 170900 T585 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230794 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230794;done=true>>]
   [junit4]   2> 170900 T585 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230794
   [junit4]   2> ASYNC  NEW_CORE C102 name=collection1 org.apache.solr.core.SolrCore@13695d3e
   [junit4]   2> 170901 T579 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:52287/solr/replication&command=fetchindex&wait=true} status=0 QTime=91 
   [junit4]   2> 170924 T577 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty1&wt=javabin&version=2} hits=1 status=0 QTime=15 
   [junit4]   2> 170928 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 170931 T561 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 170944 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
   [junit4]   2> 170959 T575 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=22 
   [junit4]   2> 170962 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 170964 T573 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 170968 T562 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 170969 T562 C101 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
   [junit4]   2> 170969 T562 C101 oass.SolrIndexSearcher.<init> Opening Searcher@5a3761b2 main
   [junit4]   2> 170970 T562 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 170971 T568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a3761b2 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):c1)}
   [junit4]   2> 170971 T562 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 3
   [junit4]   2> 170993 T587 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 170993 T587 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 170995 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 170996 T587 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
   [junit4]   2> 170996 T571 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:52287/solr/replication&command=fetchindex&wait=true} status=0 QTime=4 
   [junit4]   2> 171005 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
   [junit4]   2> 171005 T583 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
   [junit4]   2> 171007 T566 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 6
   [junit4]   2> 171009 T561 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 171012 T561 C101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_3,generation=3}
   [junit4]   2> 171013 T561 C101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 171016 T561 C101 oass.SolrIndexSearcher.<init> Opening Searcher@2db25c9c main
   [junit4]   2> 171016 T561 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 171017 T568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2db25c9c main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):c1 _1(4.5):c1)}
   [junit4]   2> 171017 T561 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 8
   [junit4]   2> 171021 T588 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 171021 T588 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 171025 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1 
   [junit4]   2> 171026 T588 oash.SnapPuller.fetchLatestIndex Master's generation: 3
   [junit4]   2> 171026 T588 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
   [junit4]   2> 171026 T588 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 171032 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=3 
   [junit4]   2> 171033 T588 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 7
   [junit4]   2> 171033 T588 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230997
   [junit4]   2> 171033 T588 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b563d58 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@416d60bd) fullCopy=false
   [junit4]   2> 171034 T588 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 171034 T588 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 171036 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 171038 T588 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 171040 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 171044 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 171051 T566 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0 
   [junit4]   2> 171052 T588 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 171056 T588 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 171056 T588 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 171056 T588 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 171057 T588 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 171057 T588 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=41.216796875, floorSegmentMB=1.5283203125, forceMergeDeletesPctAllowed=20.681333853134195, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 171058 T588 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_3,generation=3}
   [junit4]   2> 171059 T588 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
   [junit4]   2> 171059 T588 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 171061 T588 oass.SolrIndexSearcher.<init> Opening Searcher@50236623 main
   [junit4]   2> 171061 T582 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50236623 main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):c1 _1(4.5):c1)}
   [junit4]   2> 171061 T588 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230997 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230997;done=true>>]
   [junit4]   2> 171061 T588 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083230997
   [junit4]   2> 171061 T578 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:52287/solr/replication&command=fetchindex&wait=true} status=0 QTime=41 
   [junit4]   2> 171072 T579 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=1 
   [junit4]   2> 171078 T561 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 171087 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 171115 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 171121 T577 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=10 
   [junit4]   2> 171128 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 171132 T575 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 171136 T564 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 2
   [junit4]   2> 171139 T565 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 171143 T565 C101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_4,generation=4}
   [junit4]   2> 171143 T565 C101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 171144 T565 C101 oass.SolrIndexSearcher.<init> Opening Searcher@41fddb3e realtime
   [junit4]   2> 171145 T565 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 171145 T565 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2} {commit=} 0 6
   [junit4]   2> 171152 T591 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 171152 T591 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 171155 T566 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 171156 T591 oash.SnapPuller.fetchLatestIndex Master's generation: 4
   [junit4]   2> 171156 T591 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
   [junit4]   2> 171156 T591 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 171159 T561 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=0 
   [junit4]   2> 171159 T591 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
   [junit4]   2> 171160 T591 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231124
   [junit4]   2> 171160 T591 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@312aa2f8 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@25747347) fullCopy=false
   [junit4]   2> 171163 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 171164 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 171165 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 171165 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 171165 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 171165 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
   [junit4]   2> 171167 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 171171 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 171219 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0 
   [junit4]   2> 171221 T591 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
   [junit4]   2> 171221 T591 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 171224 T591 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 171224 T591 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 171224 T591 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 171224 T591 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 171227 T591 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=41.216796875, floorSegmentMB=1.5283203125, forceMergeDeletesPctAllowed=20.681333853134195, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 171230 T591 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_4,generation=4}
   [junit4]   2> 171230 T591 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
   [junit4]   2> 171231 T591 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 171239 T591 oass.SolrIndexSearcher.<init> Opening Searcher@390a4a22 main
   [junit4]   2> 171239 T582 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@390a4a22 main{StandardDirectoryReader(segments_4:7:nrt _0(4.5):c1 _1(4.5):c1 _2(4.5):c1)}
   [junit4]   2> 171240 T591 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231124 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231124;done=true>>]
   [junit4]   2> 171240 T591 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231124
   [junit4]   2> 171240 T573 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:52287/solr/replication&command=fetchindex&wait=true} status=0 QTime=89 
   [junit4]   2> 171248 T565 C101 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> 171251 T571 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=1 status=0 QTime=0 
   [junit4]   2> 171255 T566 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 0
   [junit4]   2> 171257 T561 C101 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 171260 T561 C101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@58b271ce lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3d5ab997),segFN=segments_5,generation=5}
   [junit4]   2> 171260 T561 C101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 171262 T561 C101 oass.SolrIndexSearcher.<init> Opening Searcher@3ea2c4b5 main
   [junit4]   2> 171262 T561 C101 oasu.DirectUpdateHandler2.commit end_commit_flush
   [junit4]   2> 171262 T568 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ea2c4b5 main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):c1 _1(4.5):c1 _2(4.5):c1 _3(4.5):c1)}
   [junit4]   2> 171264 T561 C101 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 7
   [junit4]   2> 171274 T593 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
   [junit4]   2> 171274 T593 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
   [junit4]   2> 171278 T563 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 171278 T593 oash.SnapPuller.fetchLatestIndex Master's generation: 5
   [junit4]   2> 171278 T593 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
   [junit4]   2> 171278 T593 oash.SnapPuller.fetchLatestIndex Starting replication process
   [junit4]   2> 171283 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=5&version=2} status=0 QTime=1 
   [junit4]   2> 171284 T593 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 13
   [junit4]   2> 171284 T593 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231248
   [junit4]   2> 171284 T593 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@7f3e779e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@379a2bb) fullCopy=false
   [junit4]   2> 171284 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
   [junit4]   2> 171289 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1 
   [junit4]   2> 171299 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfe because it already exists
   [junit4]   2> 171299 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfs because it already exists
   [junit4]   2> 171299 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfe because it already exists
   [junit4]   2> 171299 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.cfs because it already exists
   [junit4]   2> 171300 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
   [junit4]   2> 171303 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 171306 T566 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 171323 T561 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_5&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0 
   [junit4]   2> 171333 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
   [junit4]   2> 171333 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _1.cfs because it already exists
   [junit4]   2> 171338 T593 oash.SnapPuller.downloadIndexFiles Skipping download for _2.cfe because it already exists
   [junit4]   2> 171338 T593 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
   [junit4]   2> 171342 T593 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
   [junit4]   2> 171342 T593 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
   [junit4]   2> 171342 T593 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
   [junit4]   2> 171343 T593 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
   [junit4]   2> 171343 T593 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=41.216796875, floorSegmentMB=1.5283203125, forceMergeDeletesPctAllowed=20.681333853134195, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 171347 T593 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_2,generation=2}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_3,generation=3}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_4,generation=4}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5743fbc1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@77700a7c),segFN=segments_5,generation=5}
   [junit4]   2> 171348 T593 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
   [junit4]   2> 171348 T593 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 171354 T593 oass.SolrIndexSearcher.<init> Opening Searcher@66e392a8 main
   [junit4]   2> 171354 T582 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66e392a8 main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):c1 _1(4.5):c1 _2(4.5):c1 _3(4.5):c1)}
   [junit4]   2> 171355 T593 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231248 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231248;done=true>>]
   [junit4]   2> 171355 T593 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index.20130826083231248
   [junit4]   2> 171355 T578 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:52287/solr/replication&command=fetchindex&wait=true} status=0 QTime=82 
   [junit4]   2> 171364 T563 C101 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=5 
   [junit4]   2> 171376 T576 C102 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=9 
   [junit4]   2> 171387 T559 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=1 
   [junit4]   2> 171396 T562 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=2 
   [junit4]   2> 171413 T564 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=5 
   [junit4]   2> 171414 T579 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=13 
   [junit4]   2> 171425 T565 C101 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 171429 T577 C102 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&_trace=assertVersions&wt=javabin&qt=/replication&version=2} status=0 QTime=0 
   [junit4]   2> 171430 T555 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
   [junit4]   2> 171442 T555 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1398472590
   [junit4]   2> 171443 T555 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ffa0953
   [junit4]   2> 171444 T555 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> 171444 T555 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 171444 T555 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 171445 T555 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 171448 T555 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 171454 T555 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 171454 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\;done=false>>]
   [junit4]   2> 171455 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\
   [junit4]   2> 171456 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index;done=false>>]
   [junit4]   2> 171457 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150414\master\collection1\data\index
   [junit4]   2> 171457 T555 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 171523 T555 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1647837732
   [junit4]   2> 171524 T555 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@13695d3e
   [junit4]   2> 171524 T555 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> 171524 T555 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 171524 T555 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 171525 T555 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 171527 T555 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 171528 T555 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 171528 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\;done=false>>]
   [junit4]   2> 171528 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\
   [junit4]   2> 171529 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index;done=false>>]
   [junit4]   2> 171529 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495150609\slave\collection1\data\index
   [junit4]   2> 171533 T555 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 171618 T555 oas.SolrTestCaseJ4.setUp ###Starting doTestIndexAndConfigReplication
   [junit4]   2> 171631 T555 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 171635 T555 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52300
   [junit4]   2> 171636 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 171637 T555 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 171637 T555 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master
   [junit4]   2> 171638 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\'
   [junit4]   2> 171684 T555 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\solr.xml
   [junit4]   2> 171685 T555 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\solr.xml does not exist, using default configuration
   [junit4]   2> 171712 T555 oasc.CoreContainer.<init> New CoreContainer 1903948511
   [junit4]   2> 171713 T555 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\]
   [junit4]   2> 171714 T555 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 171714 T555 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 171715 T555 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 171715 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 171715 T555 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 171716 T555 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 171716 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 171716 T555 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 171717 T555 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 171718 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 171731 T604 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1
   [junit4]   2> 171731 T604 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\'
   [junit4]   2> 171766 T604 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 171778 T604 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 171779 T604 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 171784 T604 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 171815 T604 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 171815 T604 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 171815 T604 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\data\
   [junit4]   2> 171815 T604 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 171815 T604 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\data\
   [junit4]   2> 171815 T604 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\data\index/
   [junit4]   2> 171816 T604 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 171816 T604 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151582\master\collection1\data\index
   [junit4]   2> 171817 T604 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=377913605, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 171818 T604 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5e0dbbfa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@28400fdc),segFN=segments_1,generation=1}
   [junit4]   2> 171818 T604 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 171819 T604 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 171820 T604 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 171820 T604 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 171820 T604 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 171820 T604 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 171820 T604 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 171821 T604 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 171825 T604 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 171826 T604 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 171826 T604 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 171826 T604 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=5.68359375, floorSegmentMB=1.64453125, forceMergeDeletesPctAllowed=7.994477966024032, segmentsPerTier=49.0, maxCFSSegmentSizeMB=1.431640625, noCFSRatio=0.48405516479428123
   [junit4]   2> 171826 T604 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5e0dbbfa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@28400fdc),segFN=segments_1,generation=1}
   [junit4]   2> 171826 T604 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 171826 T604 oass.SolrIndexSearcher.<init> Opening Searcher@58966fda main
   [junit4]   2> 171828 T604 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
   [junit4]   2> 171828 T604 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 171828 T604 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 171828 T605 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@58966fda main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 171829 T555 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 171829 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 171829 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 171842 T555 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 171847 T555 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52303
   [junit4]   2> 171848 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 171848 T555 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 171848 T555 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave
   [junit4]   2> 171848 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\'
   [junit4]   2> 171864 T555 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\solr.xml
   [junit4]   2> 171865 T555 oasc.ConfigSolr.fromFile C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\solr.xml does not exist, using default configuration
   [junit4]   2> 171872 T555 oasc.CoreContainer.<init> New CoreContainer 219407910
   [junit4]   2> 171872 T555 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\]
   [junit4]   2> 171873 T555 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 171873 T555 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 171873 T555 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 171873 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 171874 T555 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 171874 T555 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 171874 T555 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 171874 T555 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 171875 T555 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 171875 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
   [junit4]   2> 171883 T616 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1
   [junit4]   2> 171883 T616 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\'
   [junit4]   2> 171908 T616 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 171916 T616 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 171916 T616 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 171919 T616 oass.IndexSchema.readSchema [null] Schema name=test
   [junit4]   2> 171922 T616 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 171922 T616 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 171923 T616 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\data\
   [junit4]   2> 171923 T616 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
   [junit4]   2> 171924 T616 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\data\
   [junit4]   2> 171924 T616 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\data\index/
   [junit4]   2> 171924 T616 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 171924 T616 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495151797\slave\collection1\data\index
   [junit4]   2> 171924 T616 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=377913605, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 171924 T616 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@28e58ae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2309419),segFN=segments_1,generation=1}
   [junit4]   2> 171925 T616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 171926 T616 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 171926 T616 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 171927 T616 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 171927 T616 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 171927 T616 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 171927 T616 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 171928 T616 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 171929 T616 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 171930 T616 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 171930 T616 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 171932 T616 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=48, maxMergedSegmentMB=5.68359375, floorSegmentMB=1.64453125, forceMergeDeletesPctAllowed=7.994477966024032, segmentsPerTier=49.0, maxCFSSegmentSizeMB=1.431640625, noCFSRatio=0.48405516479428123
   [junit4]   2> 171932 T616 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@28e58ae lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2309419),segFN=segments_1,generation=1}
   [junit4]   2> 171932 T616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 171932 T616 oass.SolrIndexSearcher.<init> Opening Searcher@2a0aee5d main
   [junit4]   2> 171933 T616 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
   [junit4]   2> 171934 T616 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 171935 T555 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 171935 T555 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 171935 T617 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2a0aee5d main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 171936 T555 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> ASYNC  NEW_CORE C103 name=collection1 org.apache.solr.core.SolrCore@5e640cfb
   [junit4]   2> 171944 T600 C103 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> 171948 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 1
   [junit4]   2> 171952 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 1
   [junit4]   2> 171957 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
   [junit4]   2> 171961 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 1
   [junit4]   2> 171964 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 1
   [junit4]   2> 171967 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[5]} 0 0
   [junit4]   2> 171969 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[6]} 0 0
   [junit4]   2> 171972 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[7]} 0 0
   [junit4]   2> 171974 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[8]} 0 0
   [junit4]   2> 171977 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[9]} 0 0
   [junit4]   2> 171979 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[10]} 0 0
   [junit4]   2> 171983 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[11]} 0 1
   [junit4]   2> 171984 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[12]} 0 0
   [junit4]   2> 171987 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[13]} 0 0
   [junit4]   2> 171989 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[14]} 0 0
   [junit4]   2> 171992 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[15]} 0 0
   [junit4]   2> 171996 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[16]} 0 1
   [junit4]   2> 171998 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[17]} 0 0
   [junit4]   2> 172000 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[18]} 0 0
   [junit4]   2> 172004 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[19]} 0 0
   [junit4]   2> 172009 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[20]} 0 1
   [junit4]   2> 172011 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[21]} 0 0
   [junit4]   2> 172015 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[22]} 0 0
   [junit4]   2> 172019 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[23]} 0 0
   [junit4]   2> 172022 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[24]} 0 0
   [junit4]   2> 172029 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[25]} 0 0
   [junit4]   2> 172030 T601 C103 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0 
   [junit4]   2> 172032 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[26]} 0 0
   [junit4]   2> 172035 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[27]} 0 0
   [junit4]   2> 172037 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[28]} 0 0
   [junit4]   2> 172041 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[29]} 0 0
   [junit4]   2> 172043 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[30]} 0 0
   [junit4]   2> 172046 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[31]} 0 0
   [junit4]   2> 172048 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[32]} 0 0
   [junit4]   2> 172051 T603 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[33]} 0 0
   [junit4]   2> 172054 T602 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[34]} 0 0
   [junit4]   2> 172057 T599 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[35]} 0 0
   [junit4]   2> 172059 T601 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[36]} 0 0
   [junit4]   2> 172062 T597 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[37]} 0 0
   [junit4]   2> 172065 T600 C103 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/upd

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

it: commits: num=2
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@564aca53 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3eaaa13e),segFN=segments_1,generation=1}
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@564aca53 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3eaaa13e),segFN=segments_2,generation=2}
   [junit4]   2> 245121 T1239 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
   [junit4]   2> 245121 T1239 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
   [junit4]   2> 245124 T1239 oass.SolrIndexSearcher.<init> Opening Searcher@27b32ef4 main
   [junit4]   2> 245124 T1238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27b32ef4 main{StandardDirectoryReader(segments_2:5:nrt _0(4.5):c383 _1(4.5):c109)}
   [junit4]   2> 245124 T1239 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index.20130826083345036 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index.20130826083345036;done=true>>]
   [junit4]   2> 245125 T1239 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index.20130826083345036
   [junit4]   2> 245141 T1232 C154 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=492 status=0 QTime=1 
   [junit4]   2> 245143 T555 oas.SolrTestCaseJ4.tearDown ###Ending doTestReplicateAfterStartup
   [junit4]   2> 245158 T555 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=992032229
   [junit4]   2> 245158 T555 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@593835cf
   [junit4]   2> 245160 T555 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=492,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 245160 T555 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 245160 T555 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 245161 T555 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 245164 T555 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 245164 T555 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 245164 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\;done=false>>]
   [junit4]   2> 245165 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\
   [junit4]   2> 245165 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\index;done=false>>]
   [junit4]   2> 245165 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222039\master\collection1\data\index
   [junit4]   2> 245167 T555 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 245238 T555 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=617088111
   [junit4]   2> 245240 T555 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@6d970a5b
   [junit4]   2> 245241 T555 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> 245242 T555 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 245242 T555 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 245242 T555 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 245244 T555 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 245248 T555 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 245249 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index;done=false>>]
   [junit4]   2> 245249 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\index
   [junit4]   2> 245250 T555 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\;done=false>>]
   [junit4]   2> 245250 T555 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.handler.TestReplicationHandler$SolrInstance-1377495222245\slave\collection1\data\
   [junit4]   2> 245253 T555 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 245358 T555 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=sr_RS, timezone=Africa/Asmera
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=2,threads=1,free=201514736,total=413138944
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolrQueryParserResource, UpdateRequestProcessorFactoryTest, SuggesterWFSTTest, HighlighterConfigTest, ChaosMonkeyNothingIsSafeTest, TestValueSourceCache, FileUtilsTest, JSONWriterTest, TestDocumentBuilder, TestCSVLoader, TestMaxScoreQueryParser, FullSolrCloudDistribCmdsTest, PrimitiveFieldTypeTest, SolrIndexSplitterTest, OpenExchangeRatesOrgProviderTest, HdfsUnloadDistributedZkTest, CurrencyFieldXmlFileTest, QueryEqualityTest, TestFastLRUCache, NotRequiredUniqueKeyTest, SuggesterFSTTest, StandardRequestHandlerTest, CollectionsAPIDistributedZkTest, TestRecovery, TestReplicationHandler]
   [junit4] Completed in 74.98s, 14 tests, 1 failure <<< FAILURES!

[...truncated 931 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:395: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:375: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:450: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1233: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:876: There were test failures: 325 suites, 1409 tests, 1 failure, 44 ignored (11 assumptions)

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