You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/07/27 10:11:26 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b99) - Build #
6674 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6674/
Java: 64bit/jdk1.8.0-ea-b99 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Sat Jul 27 10:07:51 CEST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Sat Jul 27 10:07:51 CEST 2013
at __randomizedtesting.SeedInfo.seed([849511A331B45A60:5F3E1165349C33D3]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1507)
at org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:811)
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 9987 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 749995 T3196 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
[junit4] 2> 749998 T3196 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 750001 T3196 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:60514
[junit4] 2> 750001 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 750002 T3196 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 750002 T3196 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master
[junit4] 2> 750002 T3196 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/'
[junit4] 2> 750012 T3196 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/solr.xml
[junit4] 2> 750013 T3196 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/solr.xml does not exist, using default configuration
[junit4] 2> 750021 T3196 oasc.CoreContainer.<init> New CoreContainer 1418155249
[junit4] 2> 750021 T3196 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/]
[junit4] 2> 750022 T3196 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 750022 T3196 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 750022 T3196 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 750022 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 750023 T3196 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 750023 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 750023 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 750023 T3196 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 750023 T3196 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 750024 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 750029 T3206 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1
[junit4] 2> 750029 T3206 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/'
[junit4] 2> 750043 T3206 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 750052 T3206 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 750052 T3206 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 750055 T3206 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 750058 T3206 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 750058 T3206 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 750058 T3206 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/
[junit4] 2> 750059 T3206 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 750059 T3206 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data
[junit4] 2> 750059 T3206 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index/
[junit4] 2> 750059 T3206 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 750059 T3206 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index
[junit4] 2> 750060 T3206 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_1,generation=1}
[junit4] 2> 750061 T3206 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 750061 T3206 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 750061 T3206 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 750062 T3206 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 750062 T3206 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 750062 T3206 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 750062 T3206 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 750064 T3206 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 750064 T3206 oass.SolrIndexSearcher.<init> Opening Searcher@6a38b476 main
[junit4] 2> 750065 T3206 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 750065 T3206 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 750065 T3206 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 750065 T3206 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 750065 T3206 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 750065 T3207 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a38b476 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 750066 T3196 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 750066 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 750067 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 750071 T3196 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 750074 T3196 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41730
[junit4] 2> 750074 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 750075 T3196 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 750075 T3196 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave
[junit4] 2> 750075 T3196 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/'
[junit4] 2> 750084 T3196 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/solr.xml
[junit4] 2> 750084 T3196 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/solr.xml does not exist, using default configuration
[junit4] 2> 750092 T3196 oasc.CoreContainer.<init> New CoreContainer 2116764366
[junit4] 2> 750092 T3196 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/]
[junit4] 2> 750093 T3196 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 750093 T3196 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 750093 T3196 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 750093 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 750094 T3196 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 750094 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 750094 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 750094 T3196 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 750094 T3196 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 750095 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 750099 T3218 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1
[junit4] 2> 750099 T3218 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/'
[junit4] 2> 750112 T3218 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 750126 T3218 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 750126 T3218 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 750128 T3218 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 750131 T3218 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 750131 T3218 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 750132 T3218 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/
[junit4] 2> 750132 T3218 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 750132 T3218 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data
[junit4] 2> 750132 T3218 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index/
[junit4] 2> 750133 T3218 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 750133 T3218 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index
[junit4] 2> 750134 T3218 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_1,generation=1}
[junit4] 2> 750134 T3218 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 750135 T3218 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 750135 T3218 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 750135 T3218 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 750135 T3218 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 750135 T3218 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 750136 T3218 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 750136 T3218 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 750137 T3218 oass.SolrIndexSearcher.<init> Opening Searcher@4f4d70b1 main
[junit4] 2> 750138 T3218 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 750138 T3218 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 750141 T3218 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 750142 T3218 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 750142 T3219 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f4d70b1 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 750142 T3196 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 750143 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 750143 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C2386 name=collection1 org.apache.solr.core.SolrCore@305a2073
[junit4] 2> 750151 T3202 C2386 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> 750154 T3203 C2386 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_1,generation=1}
[junit4] 2> 750155 T3203 C2386 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 750156 T3203 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 3
[junit4] 2> 750158 T3204 C2386 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 750160 T3204 C2386 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_2,generation=2}
[junit4] 2> 750160 T3204 C2386 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 750162 T3204 C2386 oass.SolrIndexSearcher.<init> Opening Searcher@303f29cd main
[junit4] 2> 750162 T3204 C2386 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 750162 T3207 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@303f29cd main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 750162 T3204 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
[junit4] 2> 750166 T3222 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 750166 T3222 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 750167 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 750168 T3222 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 750168 T3222 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4] 2> 750168 T3222 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 750172 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2
[junit4] 2> 750172 T3222 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4] 2> 750173 T3222 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738362
[junit4] 2> 750173 T3222 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4b8d744e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3fcb1d2f) fullCopy=false
[junit4] 2> 750175 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750177 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750180 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750182 T3202 C2386 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> 750184 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750186 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750188 T3205 C2386 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> 750191 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750193 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750195 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 750196 T3222 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 750197 T3222 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 750197 T3222 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 750197 T3222 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 750198 T3222 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_2,generation=2}
[junit4] 2> 750198 T3222 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 750199 T3222 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 750199 T3222 oass.SolrIndexSearcher.<init> Opening Searcher@76578197 main
[junit4] 2> 750200 T3219 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@76578197 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 750200 T3222 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738362 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738362;done=true>>]
[junit4] 2> 750200 T3222 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738362
[junit4] 2> ASYNC NEW_CORE C2387 name=collection1 org.apache.solr.core.SolrCore@39595912
[junit4] 2> 750200 T3214 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60514/solr/replication&command=fetchindex&wait=true} status=0 QTime=35
[junit4] 2> 750203 T3215 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty1&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 750206 T3205 C2386 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> 750208 T3202 C2386 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> 750212 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 750213 T3216 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 750215 T3204 C2386 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> 750216 T3217 C2387 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> 750218 T3205 C2386 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 750218 T3205 C2386 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 750219 T3205 C2386 oass.SolrIndexSearcher.<init> Opening Searcher@7092ffcd main
[junit4] 2> 750219 T3205 C2386 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 750219 T3207 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7092ffcd main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 750219 T3205 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 1
[junit4] 2> 750220 T3225 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 750220 T3225 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 750222 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 750222 T3225 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 750222 T3214 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60514/solr/replication&command=fetchindex&wait=true} status=0 QTime=2
[junit4] 2> 750224 T3203 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 0
[junit4] 2> 750226 T3204 C2386 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 750227 T3204 C2386 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_3,generation=3}
[junit4] 2> 750227 T3204 C2386 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 750228 T3204 C2386 oass.SolrIndexSearcher.<init> Opening Searcher@51aa78d main
[junit4] 2> 750228 T3204 C2386 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 750228 T3207 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51aa78d main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):C1 _1(4.5):C1)}
[junit4] 2> 750229 T3204 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 3
[junit4] 2> 750230 T3226 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 750230 T3226 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 750232 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 750232 T3226 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 750232 T3226 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 750232 T3226 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 750234 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=0
[junit4] 2> 750235 T3226 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4] 2> 750236 T3226 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738425
[junit4] 2> 750236 T3226 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@349619d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3b71f1da) fullCopy=false
[junit4] 2> 750238 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750241 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750242 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 750244 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750246 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750247 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfs because it already exists
[junit4] 2> 750249 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750252 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750255 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750256 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4] 2> 750258 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 750260 T3203 C2386 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> 750261 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfe because it already exists
[junit4] 2> 750261 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 750262 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 750262 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4] 2> 750262 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 750262 T3226 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4] 2> 750264 T3204 C2386 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> 750265 T3226 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 750267 T3226 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 750267 T3226 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 750267 T3226 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 750268 T3226 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 750270 T3226 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_3,generation=3}
[junit4] 2> 750271 T3226 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 750271 T3226 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 750273 T3226 oass.SolrIndexSearcher.<init> Opening Searcher@7efd0de2 main
[junit4] 2> 750274 T3219 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7efd0de2 main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):C1 _1(4.5):C1)}
[junit4] 2> 750274 T3226 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738425 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738425;done=true>>]
[junit4] 2> 750275 T3226 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738425
[junit4] 2> 750275 T3215 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60514/solr/replication&command=fetchindex&wait=true} status=0 QTime=45
[junit4] 2> 750278 T3216 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 750281 T3205 C2386 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> 750283 T3202 C2386 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> 750288 T3203 C2386 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> 750289 T3217 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=4
[junit4] 2> 750291 T3204 C2386 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> 750293 T3214 C2387 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> 750296 T3205 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 1
[junit4] 2> 750298 T3202 C2386 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 750301 T3202 C2386 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_4,generation=4}
[junit4] 2> 750302 T3202 C2386 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 750303 T3202 C2386 oass.SolrIndexSearcher.<init> Opening Searcher@fe59368 realtime
[junit4] 2> 750303 T3202 C2386 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 750304 T3202 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2} {commit=} 0 6
[junit4] 2> 750305 T3228 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 750306 T3228 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 750307 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 750308 T3228 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4] 2> 750308 T3228 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 750308 T3228 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 750311 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=1
[junit4] 2> 750311 T3228 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4] 2> 750312 T3228 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738502
[junit4] 2> 750313 T3228 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5599d42f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3e599a25) fullCopy=false
[junit4] 2> 750315 T3205 C2386 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=1
[junit4] 2> 750316 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.doc because it already exists
[junit4] 2> 750318 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=1
[junit4] 2> 750320 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750321 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 750323 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750324 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 750326 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750327 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4] 2> 750327 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4] 2> 750328 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1_nrm.cfs because it already exists
[junit4] 2> 750328 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 750328 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tim because it already exists
[junit4] 2> 750330 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750331 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tip because it already exists
[junit4] 2> 750333 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750334 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfs because it already exists
[junit4] 2> 750336 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750337 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1_nrm.cfe because it already exists
[junit4] 2> 750339 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 750340 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 750340 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 750340 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4] 2> 750340 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 750341 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfe because it already exists
[junit4] 2> 750341 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 750341 T3228 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 750343 T3202 C2386 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> 750344 T3228 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 750345 T3228 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 750345 T3228 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 750345 T3228 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 750347 T3228 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 750349 T3228 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_4,generation=4}
[junit4] 2> 750350 T3228 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 750350 T3228 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 750352 T3228 oass.SolrIndexSearcher.<init> Opening Searcher@6ac29485 main
[junit4] 2> 750353 T3219 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ac29485 main{StandardDirectoryReader(segments_4:7:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1)}
[junit4] 2> 750353 T3228 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738502 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738502;done=true>>]
[junit4] 2> 750353 T3228 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738502
[junit4] 2> 750353 T3215 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60514/solr/replication&command=fetchindex&wait=true} status=0 QTime=48
[junit4] 2> 750357 T3203 C2386 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> 750360 T3216 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 750362 T3204 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 0
[junit4] 2> 750364 T3205 C2386 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 750367 T3205 C2386 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59d15cd7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@163824d0),segFN=segments_5,generation=5}
[junit4] 2> 750367 T3205 C2386 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 750368 T3205 C2386 oass.SolrIndexSearcher.<init> Opening Searcher@199505b7 main
[junit4] 2> 750369 T3205 C2386 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 750369 T3207 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@199505b7 main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1 _3(4.5):C1)}
[junit4] 2> 750370 T3205 C2386 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 6
[junit4] 2> 750371 T3230 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 750372 T3230 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 750374 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 750374 T3230 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4] 2> 750374 T3230 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4] 2> 750374 T3230 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 750377 T3203 C2386 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> 750377 T3230 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 37
[junit4] 2> 750378 T3230 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738568
[junit4] 2> 750378 T3230 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3feed628 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f1df62) fullCopy=false
[junit4] 2> 750379 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4] 2> 750381 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_nrm.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750382 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.doc because it already exists
[junit4] 2> 750382 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.tim because it already exists
[junit4] 2> 750384 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750387 T3202 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750388 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.tip because it already exists
[junit4] 2> 750388 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 750388 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2_nrm.cfe because it already exists
[junit4] 2> 750390 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750393 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750394 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 750394 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2_nrm.cfs because it already exists
[junit4] 2> 750395 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tim because it already exists
[junit4] 2> 750395 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.tip because it already exists
[junit4] 2> 750395 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1_nrm.cfs because it already exists
[junit4] 2> 750395 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 750395 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tim because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1_Lucene41_0.tip because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2_Lucene41_0.doc because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfs because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
[junit4] 2> 750396 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1_nrm.cfe because it already exists
[junit4] 2> 750397 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
[junit4] 2> 750399 T3205 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750400 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 750402 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_nrm.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=1
[junit4] 2> 750404 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_Lucene41_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 750406 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 750406 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0_Lucene41_0.doc because it already exists
[junit4] 2> 750406 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 750406 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0_nrm.cfe because it already exists
[junit4] 2> 750406 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 750408 T3205 C2386 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> 750411 T3202 C2386 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> 750412 T3230 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 750413 T3230 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 750413 T3230 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 750414 T3230 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 750414 T3230 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 750415 T3230 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 750418 T3230 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ad9575a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7454720f),segFN=segments_5,generation=5}
[junit4] 2> 750419 T3230 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 750419 T3230 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 750472 T3230 oass.SolrIndexSearcher.<init> Opening Searcher@7c1629d8 main
[junit4] 2> 750472 T3219 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c1629d8 main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1 _3(4.5):C1)}
[junit4] 2> 750472 T3230 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738568 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738568;done=true>>]
[junit4] 2> 750473 T3230 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index.20130727100738568
[junit4] 2> 750473 T3217 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:60514/solr/replication&command=fetchindex&wait=true} status=0 QTime=102
[junit4] 2> 750476 T3203 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=1
[junit4] 2> 750478 T3214 C2387 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:(empty1+empty2+empty3+empty4)&wt=javabin&version=2} hits=4 status=0 QTime=1
[junit4] 2> 750480 T3205 C2386 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> 750482 T3202 C2386 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> 750485 T3204 C2386 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 750486 T3216 C2387 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> 750488 T3203 C2386 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> 750490 T3217 C2387 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> 750490 T3196 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4] 2> 750510 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1418155249
[junit4] 2> 750511 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@305a2073
[junit4] 2> 750511 T3196 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> 750512 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 750512 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 750512 T3196 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 750513 T3196 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 750513 T3196 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 750513 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index;done=false>>]
[junit4] 2> 750514 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data/index
[junit4] 2> 750514 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data;done=false>>]
[junit4] 2> 750514 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458185/master/collection1/data
[junit4] 2> 750514 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 750587 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2116764366
[junit4] 2> 750588 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@39595912
[junit4] 2> 750589 T3196 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> 750590 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 750590 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 750591 T3196 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 750592 T3196 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 750593 T3196 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 750593 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data;done=false>>]
[junit4] 2> 750594 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data
[junit4] 2> 750594 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index;done=false>>]
[junit4] 2> 750595 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458259/slave/collection1/data/index
[junit4] 2> 750595 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 750659 T3196 oas.SolrTestCaseJ4.setUp ###Starting doTestReplicateAfterCoreReload
[junit4] 2> 750665 T3196 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 750667 T3196 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58342
[junit4] 2> 750668 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 750669 T3196 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 750669 T3196 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master
[junit4] 2> 750669 T3196 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/'
[junit4] 2> 750679 T3196 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/solr.xml
[junit4] 2> 750679 T3196 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/solr.xml does not exist, using default configuration
[junit4] 2> 750691 T3196 oasc.CoreContainer.<init> New CoreContainer 851725382
[junit4] 2> 750691 T3196 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/]
[junit4] 2> 750691 T3196 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 750692 T3196 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 750692 T3196 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 750692 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 750692 T3196 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 750692 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 750693 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 750693 T3196 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 750693 T3196 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 750693 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 750698 T3241 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1
[junit4] 2> 750698 T3241 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/'
[junit4] 2> 750714 T3241 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 750720 T3241 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 750720 T3241 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 750722 T3241 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 750725 T3241 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 750725 T3241 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 750726 T3241 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/data/
[junit4] 2> 750726 T3241 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 750726 T3241 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/data
[junit4] 2> 750727 T3241 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/data/index/
[junit4] 2> 750727 T3241 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 750727 T3241 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458850/master/collection1/data/index
[junit4] 2> 750728 T3241 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@263c703d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@11344dfb),segFN=segments_1,generation=1}
[junit4] 2> 750728 T3241 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 750729 T3241 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 750731 T3241 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 750732 T3241 oass.SolrIndexSearcher.<init> Opening Searcher@63b7fa0f main
[junit4] 2> 750732 T3241 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 750732 T3241 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 750732 T3241 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 750732 T3241 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 750732 T3241 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 750732 T3242 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63b7fa0f main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 750733 T3196 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 750733 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 750733 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 750743 T3196 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 750746 T3196 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53840
[junit4] 2> 750746 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 750747 T3196 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 750747 T3196 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave
[junit4] 2> 750748 T3196 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/'
[junit4] 2> 750763 T3196 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/solr.xml
[junit4] 2> 750763 T3196 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/solr.xml does not exist, using default configuration
[junit4] 2> 750772 T3196 oasc.CoreContainer.<init> New CoreContainer 1647376134
[junit4] 2> 750772 T3196 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/]
[junit4] 2> 750772 T3196 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 750773 T3196 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 750773 T3196 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 750773 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 750773 T3196 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 750773 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 750774 T3196 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 750774 T3196 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 750774 T3196 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 750774 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 750778 T3253 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1
[junit4] 2> 750778 T3253 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/'
[junit4] 2> 750799 T3253 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 750809 T3253 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 750809 T3253 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 750811 T3253 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 750814 T3253 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 750814 T3253 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 750814 T3253 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/
[junit4] 2> 750814 T3253 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 750815 T3253 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data
[junit4] 2> 750815 T3253 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index/
[junit4] 2> 750815 T3253 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 750815 T3253 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index
[junit4] 2> 750816 T3253 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3384528e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@27a0091d),segFN=segments_1,generation=1}
[junit4] 2> 750816 T3253 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 750817 T3253 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 750817 T3253 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 750817 T3253 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 750817 T3253 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 750817 T3253 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 750818 T3253 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 750818 T3253 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 750819 T3253 oass.SolrIndexSearcher.<init> Opening Searcher@31c8eae3 main
[junit4] 2> 750819 T3253 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 750820 T3253 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 750820 T3253 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 750820 T3254 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31c8eae3 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 750820 T3253 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 750821 T3196 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 750821 T3196 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 750821 T3196 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 750845 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1647376134
[junit4] 2> 750846 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6fdea47e
[junit4] 2> 750847 T3196 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> 750848 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 750848 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 750848 T3196 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 750849 T3196 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 750849 T3196 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 750849 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index;done=false>>]
[junit4] 2> 750850 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data/index
[junit4] 2> 750850 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data;done=false>>]
[junit4] 2> 750851 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912458928/slave/collection1/data
[junit4] 2> 750851 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 750926 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=851725382
[junit4] 2> 750927 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6a0b75c4
[junit4] 2> 750927 T3196 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> 750928 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 750928 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState
[...truncated too long message...]
nHandler$SolrInstance-1374912520534/repeater/collection1/data/index
[junit4] 2> 812434 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520534/repeater/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520534/repeater/collection1/data;done=false>>]
[junit4] 2> 812434 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520534/repeater/collection1/data
[junit4] 2> 812435 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 812487 T3196 oas.SolrTestCaseJ4.tearDown ###Ending doTestDetails
[junit4] 2> 812508 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=390163094
[junit4] 2> 812509 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@c08dba8
[junit4] 2> 812509 T3196 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 812509 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 812509 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 812510 T3196 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 812510 T3196 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 812511 T3196 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 812511 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data/index;done=false>>]
[junit4] 2> 812511 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data/index
[junit4] 2> 812511 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data;done=false>>]
[junit4] 2> 812511 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520250/master/collection1/data
[junit4] 2> 812512 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 812584 T3196 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=729440364
[junit4] 2> 812585 T3196 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@417c3d0
[junit4] 2> 812585 T3196 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> 812586 T3196 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 812586 T3196 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 812586 T3196 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 812587 T3196 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 812587 T3196 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 812587 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data/index;done=false>>]
[junit4] 2> 812587 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data/index
[junit4] 2> 812588 T3196 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data;done=false>>]
[junit4] 2> 812588 T3196 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374912520321/slave/collection1/data
[junit4] 2> 812588 T3196 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 812643 T3196 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=es_DO, timezone=Europe/Stockholm
[junit4] 2> NOTE: Linux 3.2.0-49-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=156206088,total=405274624
[junit4] 2> NOTE: All tests run in this JVM: [TestSolr4Spatial, TestComponentsName, DirectUpdateHandlerTest, TestJmxMonitoredMap, TestSolrJ, TestQueryTypes, IndexReaderFactoryTest, SolrPluginUtilsTest, AssignTest, BasicDistributedZk2Test, DeleteShardTest, TestMergePolicyConfig, HdfsRecoveryZkTest, SignatureUpdateProcessorFactoryTest, TestRecovery, ZkNodePropsTest, TestCloudManagedSchema, BasicZkTest, URLClassifyProcessorTest, TestJmxIntegration, TestDistributedGrouping, CoreContainerCoreInitFailuresTest, HardAutoCommitTest, TestBinaryResponseWriter, TestSchemaVersionResource, TestSystemIdResolver, TestDFRSimilarityFactory, TestLuceneMatchVersion, TestBM25SimilarityFactory, TestPropInject, TimeZoneUtilsTest, UpdateParamsTest, TestOmitPositions, RequiredFieldsTest, ClusterStateTest, CopyFieldTest, ZkSolrClientTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, DOMUtilTest, NumericFieldsTest, PingRequestHandlerTest, EchoParamsTest, TestCollationKeyRangeQueries, TestLazyCores, BadIndexSchemaTest, TestManagedSchemaFieldResource, CollectionsAPIDistributedZkTest, TestUpdate, TestArbitraryIndexDir, UniqFieldsUpdateProcessorFactoryTest, XsltUpdateRequestHandlerTest, TestSchemaSimilarityResource, TestFieldCollectionResource, DebugComponentTest, ConvertedLegacyTest, TestRandomFaceting, DistanceFunctionTest, TestDynamicFieldResource, TestStressLucene, DefaultValueUpdateProcessorTest, SolrCmdDistributorTest, TestCoreDiscovery, HighlighterTest, CurrencyFieldOpenExchangeTest, TestCollationField, HdfsCollectionsAPIDistributedZkTest, ShardSplitTest, TestReloadAndDeleteDocs, TestSchemaResource, HdfsBasicDistributedZk2Test, TestDistributedSearch, TestUtils, NotRequiredUniqueKeyTest, IndexSchemaRuntimeFieldTest, ChaosMonkeySafeLeaderTest, OverseerTest, ShardRoutingTest, TestReplicationHandler]
[junit4] Completed on J1 in 62.69s, 14 tests, 1 failure <<< FAILURES!
[...truncated 462 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:395: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:375: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:449: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 319 suites, 1345 tests, 1 failure, 37 ignored (6 assumptions)
Total time: 34 minutes 40 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b99 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure