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/23 16:43:17 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_25) - Build # 6619
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6619/
Java: 64bit/jdk1.7.0_25 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestStressReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Tue Jul 23 15:37:05 BST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Tue Jul 23 15:37:05 BST 2013
at __randomizedtesting.SeedInfo.seed([E61D35206AB92A76:3DB635E66F9143C5]: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:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9893 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 925666 T2563 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
[junit4] 2> 925670 T2563 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 925831 T2563 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55076
[junit4] 2> 925832 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 925833 T2563 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 925833 T2563 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master
[junit4] 2> 925833 T2563 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/'
[junit4] 2> 925846 T2563 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-1374590203331/master/solr.xml
[junit4] 2> 925846 T2563 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/solr.xml does not exist, using default configuration
[junit4] 2> 925876 T2563 oasc.CoreContainer.<init> New CoreContainer 250405736
[junit4] 2> 925876 T2563 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/]
[junit4] 2> 925877 T2563 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 925878 T2563 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 925878 T2563 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 925878 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 925879 T2563 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 925879 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 925879 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 925879 T2563 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 925880 T2563 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 925880 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 925887 T2573 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/collection1
[junit4] 2> 925888 T2573 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/collection1/'
[junit4] 2> 925922 T2573 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 925992 T2573 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 925992 T2573 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 925995 T2573 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 926005 T2573 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 926006 T2573 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 926006 T2573 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203331/master/collection1/data/
[junit4] 2> 926006 T2573 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 926007 T2573 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-1374590203331/master/collection1/data
[junit4] 2> 926007 T2573 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-1374590203331/master/collection1/data/index/
[junit4] 2> 926007 T2573 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-1374590203331/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 926007 T2573 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-1374590203331/master/collection1/data/index
[junit4] 2> 926008 T2573 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> 926008 T2573 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 926009 T2573 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 926010 T2573 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 926010 T2573 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 926010 T2573 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 926010 T2573 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 926010 T2573 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 926013 T2573 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 926015 T2573 oass.SolrIndexSearcher.<init> Opening Searcher@64c449d2 main
[junit4] 2> 926015 T2573 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 926015 T2573 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 926016 T2573 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 926016 T2573 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 926016 T2573 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 926016 T2574 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64c449d2 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 926016 T2563 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 926017 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 926017 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 926021 T2563 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 926024 T2563 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49879
[junit4] 2> 926024 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 926024 T2563 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 926025 T2563 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave
[junit4] 2> 926025 T2563 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/'
[junit4] 2> 926035 T2563 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-1374590203683/slave/solr.xml
[junit4] 2> 926036 T2563 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/solr.xml does not exist, using default configuration
[junit4] 2> 926063 T2563 oasc.CoreContainer.<init> New CoreContainer 1376588860
[junit4] 2> 926063 T2563 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/]
[junit4] 2> 926064 T2563 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 926065 T2563 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 926065 T2563 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 926065 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 926066 T2563 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 926066 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 926066 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 926066 T2563 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 926067 T2563 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 926067 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 926072 T2585 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/collection1
[junit4] 2> 926072 T2585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/collection1/'
[junit4] 2> 926097 T2585 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 926123 T2585 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 926123 T2585 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 926127 T2585 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 926136 T2585 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 926136 T2585 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 926137 T2585 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590203683/slave/collection1/data/
[junit4] 2> 926137 T2585 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 926137 T2585 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-1374590203683/slave/collection1/data
[junit4] 2> 926138 T2585 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-1374590203683/slave/collection1/data/index/
[junit4] 2> 926138 T2585 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-1374590203683/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 926138 T2585 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-1374590203683/slave/collection1/data/index
[junit4] 2> 926139 T2585 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> 926139 T2585 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 926140 T2585 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 926141 T2585 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 926141 T2585 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 926141 T2585 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 926141 T2585 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 926141 T2585 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 926143 T2585 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 926144 T2585 oass.SolrIndexSearcher.<init> Opening Searcher@16d1798c main
[junit4] 2> 926145 T2585 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 926145 T2585 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 926146 T2585 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 926147 T2585 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 926147 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16d1798c main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 926147 T2563 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 926147 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 926148 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C2110 name=collection1 org.apache.solr.core.SolrCore@486858c4
[junit4] 2> 926155 T2571 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=1
[junit4] 2> 926159 T2572 C2110 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> 926160 T2572 C2110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 926160 T2572 C2110 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 2
[junit4] 2> 926163 T2569 C2110 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 926164 T2569 C2110 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> 926164 T2569 C2110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 926165 T2569 C2110 oass.SolrIndexSearcher.<init> Opening Searcher@27c5a6d5 main
[junit4] 2> 926166 T2569 C2110 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 926166 T2574 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27c5a6d5 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 926166 T2569 C2110 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 3
[junit4] 2> 926171 T2589 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 926171 T2589 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 926173 T2570 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 926173 T2589 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 926173 T2589 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4] 2> 926173 T2589 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 926177 T2571 C2110 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> 926177 T2589 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 11
[junit4] 2> 926178 T2589 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-1374590203683/slave/collection1/data/index.20130723153643842
[junit4] 2> 926178 T2589 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@143fd003 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6b4b4120) fullCopy=false
[junit4] 2> 926180 T2572 C2110 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> 926183 T2569 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 926185 T2570 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 926188 T2571 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 926190 T2572 C2110 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> 926193 T2569 C2110 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> 926195 T2570 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 926196 T2589 oash.SnapPuller$DirectoryFileFetcher.fetchPackets WARN No content recieved for file: {name=_0_MockVariableIntBlock_0.skp, size=0}
[junit4] 2> 926198 T2571 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 926200 T2572 C2110 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> 926203 T2569 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4] 2> 926205 T2570 C2110 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> 926206 T2589 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 926206 T2589 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 926206 T2589 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 926207 T2589 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 926208 T2589 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> 926208 T2589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 926208 T2589 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 926209 T2589 oass.SolrIndexSearcher.<init> Opening Searcher@7c8e1881 main
[junit4] 2> 926209 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c8e1881 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 926209 T2589 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-1374590203683/slave/collection1/data/index.20130723153643842 [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-1374590203683/slave/collection1/data/index.20130723153643842;done=true>>]
[junit4] 2> 926210 T2589 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-1374590203683/slave/collection1/data/index.20130723153643842
[junit4] 2> ASYNC NEW_CORE C2111 name=collection1 org.apache.solr.core.SolrCore@67ec60b8
[junit4] 2> 926210 T2581 C2111 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:55076/solr/replication&command=fetchindex&wait=true} status=0 QTime=39
[junit4] 2> 926212 T2582 C2111 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> 926215 T2571 C2110 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> 926217 T2572 C2110 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> 926221 T2569 C2110 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> 926221 T2583 C2111 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> 926223 T2570 C2110 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> 926225 T2584 C2111 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> 926227 T2571 C2110 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 926227 T2571 C2110 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 926228 T2571 C2110 oass.SolrIndexSearcher.<init> Opening Searcher@53cbb621 main
[junit4] 2> 926228 T2571 C2110 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 926228 T2574 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53cbb621 main{StandardDirectoryReader(segments_2:3:nrt _0(4.5):C1)}
[junit4] 2> 926228 T2571 C2110 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 1
[junit4] 2> 926229 T2592 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 926230 T2592 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 926231 T2572 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 926232 T2592 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 926232 T2581 C2111 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:55076/solr/replication&command=fetchindex&wait=true} status=0 QTime=3
[junit4] 2> 926235 T2569 C2110 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 1
[junit4] 2> 926237 T2570 C2110 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 926239 T2570 C2110 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> 926239 T2570 C2110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 926240 T2570 C2110 oass.SolrIndexSearcher.<init> Opening Searcher@33e881f8 main
[junit4] 2> 926240 T2570 C2110 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 926240 T2574 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33e881f8 main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):C1 _1(4.5):C1)}
[junit4] 2> 926241 T2570 C2110 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
[junit4] 2> 926242 T2593 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 926242 T2593 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 926244 T2571 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 926244 T2593 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 926244 T2593 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 926244 T2593 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 926246 T2572 C2110 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> 926247 T2593 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 21
[junit4] 2> 926247 T2593 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-1374590203683/slave/collection1/data/index.20130723153643911
[junit4] 2> 926248 T2593 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1663b94b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@208e605a) fullCopy=false
[junit4] 2> 926249 T2569 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 926250 T2593 oash.SnapPuller$DirectoryFileFetcher.fetchPackets WARN No content recieved for file: {name=_1_MockVariableIntBlock_0.skp, size=0}
[junit4] 2> 926253 T2570 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=1
[junit4] 2> 926254 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 926254 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926256 T2571 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=1
[junit4] 2> 926258 T2572 C2110 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 926259 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> 926259 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 926261 T2569 C2110 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> ASYNC NEW_CORE C2112 name=collection1 org.apache.solr.core.SolrCore@486858c4
[junit4] 2> 926286 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 926289 T2571 C2112 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> 926290 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926292 T2572 C2112 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> 926295 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 926298 T2570 C2112 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> 926299 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 926299 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 926299 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 926299 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 926300 T2593 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926302 T2571 C2112 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=1
[junit4] 2> 926303 T2593 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 926304 T2593 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 926304 T2593 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 926304 T2593 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 926305 T2593 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 926307 T2593 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> 926307 T2593 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 926307 T2593 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 926309 T2593 oass.SolrIndexSearcher.<init> Opening Searcher@63fb0f7c main
[junit4] 2> 926309 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63fb0f7c main{StandardDirectoryReader(segments_3:5:nrt _0(4.5):C1 _1(4.5):C1)}
[junit4] 2> 926310 T2593 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-1374590203683/slave/collection1/data/index.20130723153643911 [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-1374590203683/slave/collection1/data/index.20130723153643911;done=true>>]
[junit4] 2> 926310 T2593 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-1374590203683/slave/collection1/data/index.20130723153643911
[junit4] 2> ASYNC NEW_CORE C2113 name=collection1 org.apache.solr.core.SolrCore@67ec60b8
[junit4] 2> 926310 T2582 C2113 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:55076/solr/replication&command=fetchindex&wait=true} status=0 QTime=68
[junit4] 2> 926313 T2584 C2113 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty2&wt=javabin&version=2} hits=1 status=0 QTime=1
[junit4] 2> 926315 T2572 C2112 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> 926317 T2569 C2112 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> 926322 T2570 C2112 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> 926323 T2581 C2113 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> 926325 T2571 C2112 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> 926327 T2582 C2113 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> 926329 T2572 C2112 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[3]} 0 0
[junit4] 2> 926331 T2569 C2112 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 926425 T2569 C2112 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_4,generation=4}
[junit4] 2> 926427 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 926429 T2569 C2112 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 926429 T2587 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 926430 T2569 C2112 oass.SolrIndexSearcher.<init> Opening Searcher@4023710b realtime
[junit4] 2> 926431 T2569 C2112 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 926431 T2569 C2112 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2} {commit=} 0 100
[junit4] 2> 926433 T2595 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 926433 T2595 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 926435 T2571 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 926435 T2595 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4] 2> 926436 T2595 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 926436 T2595 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 926437 T2572 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=0
[junit4] 2> 926438 T2595 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 31
[junit4] 2> 926438 T2595 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-1374590203683/slave/collection1/data/index.20130723153644102
[junit4] 2> 926439 T2595 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@40d6ed8a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1c6c4ef8) fullCopy=false
[junit4] 2> 926440 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926441 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> 926442 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926442 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> 926442 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 926444 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926444 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926445 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926445 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 926445 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 926445 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926447 T2571 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926448 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4] 2> 926448 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 926448 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926450 T2572 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926451 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4] 2> 926453 T2570 C2112 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=1
[junit4] 2> 926453 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 926455 T2569 C2112 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> 926456 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926458 T2571 C2112 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> 926459 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 926461 T2572 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926461 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 926462 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 926463 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926464 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 926466 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 926467 T2595 oash.SnapPuller$DirectoryFileFetcher.fetchPackets WARN No content recieved for file: {name=_2_MockVariableIntBlock_0.skp, size=0}
[junit4] 2> 926467 T2595 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 926469 T2571 C2112 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> 926469 T2595 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 926470 T2595 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 926470 T2595 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 926470 T2595 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 926471 T2595 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 926472 T2595 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_4,generation=4}
[junit4] 2> 926472 T2595 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 926473 T2595 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 926474 T2595 oass.SolrIndexSearcher.<init> Opening Searcher@5599dbcf main
[junit4] 2> 926474 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5599dbcf main{StandardDirectoryReader(segments_4:7:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1)}
[junit4] 2> 926474 T2595 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-1374590203683/slave/collection1/data/index.20130723153644102 [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-1374590203683/slave/collection1/data/index.20130723153644102;done=true>>]
[junit4] 2> 926475 T2595 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-1374590203683/slave/collection1/data/index.20130723153644102
[junit4] 2> 926475 T2584 C2113 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:55076/solr/replication&command=fetchindex&wait=true} status=0 QTime=42
[junit4] 2> 926477 T2572 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=name:empty3&wt=javabin&version=2} hits=0 status=0 QTime=0
[junit4] 2> 926480 T2581 C2113 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> 926482 T2569 C2112 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[4]} 0 0
[junit4] 2> 926484 T2571 C2112 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 926486 T2571 C2112 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@5dbc671a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1d4a707c; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_5,generation=5}
[junit4] 2> 926486 T2571 C2112 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 926487 T2571 C2112 oass.SolrIndexSearcher.<init> Opening Searcher@54aa5c6f main
[junit4] 2> 926488 T2571 C2112 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 926488 T2574 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54aa5c6f main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1 _3(4.5):C1)}
[junit4] 2> 926488 T2571 C2112 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2} {commit=} 0 4
[junit4] 2> 926490 T2597 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 926490 T2597 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 926492 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 926492 T2597 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4] 2> 926492 T2597 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4] 2> 926493 T2597 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 926494 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=5&version=2} status=0 QTime=0
[junit4] 2> 926495 T2597 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 41
[junit4] 2> 926496 T2597 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-1374590203683/slave/collection1/data/index.20130723153644159
[junit4] 2> 926496 T2597 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@18f289a3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306ee2d6) fullCopy=false
[junit4] 2> 926496 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4] 2> 926496 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> 926496 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926496 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> 926498 T2571 C2112 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> 926501 T2572 C2112 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> 926502 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 926502 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926503 T2570 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_MockVariableIntBlock_0.tii&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926506 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926507 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926507 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.doc because it already exists
[junit4] 2> 926507 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 926509 T2571 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926509 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 926509 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.tii because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926510 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4] 2> 926512 T2572 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_MockVariableIntBlock_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926513 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
[junit4] 2> 926513 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 926513 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
[junit4] 2> 926513 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1_MockVariableIntBlock_0.tib because it already exists
[junit4] 2> 926513 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
[junit4] 2> 926515 T2570 C2112 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> 926516 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 926516 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvm because it already exists
[junit4] 2> 926516 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 926516 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 926516 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvd because it already exists
[junit4] 2> 926518 T2569 C2112 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_MockVariableIntBlock_0.tib&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926519 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 926521 T2571 C2112 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> 926523 T2572 C2112 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> 926544 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _2_MockVariableIntBlock_0.skp because it already exists
[junit4] 2> ASYNC NEW_CORE C2114 name=collection1 org.apache.solr.core.SolrCore@486858c4
[junit4] 2> 926546 T2570 C2114 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_3_MockVariableIntBlock_0.skp&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=5} status=0 QTime=0
[junit4] 2> 926547 T2597 oash.SnapPuller$DirectoryFileFetcher.fetchPackets WARN No content recieved for file: {name=_3_MockVariableIntBlock_0.skp, size=0}
[junit4] 2> 926547 T2597 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 926547 T2597 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 926547 T2597 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 926548 T2597 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 926548 T2597 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 926548 T2597 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 926550 T2597 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@14a76937 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@73c1b485; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_5,generation=5}
[junit4] 2> 926551 T2597 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 926551 T2597 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 926553 T2597 oass.SolrIndexSearcher.<init> Opening Searcher@73d6c269 main
[junit4] 2> 926553 T2586 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73d6c269 main{StandardDirectoryReader(segments_5:9:nrt _0(4.5):C1 _1(4.5):C1 _2(4.5):C1 _3(4.5):C1)}
[junit4] 2> 926553 T2597 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-1374590203683/slave/collection1/data/index.20130723153644159 [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-1374590203683/slave/collection1/data/index.20130723153644159;done=true>>]
[junit4] 2> 926553 T2597 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-1374590203683/slave/collection1/data/index.20130723153644159
[junit4] 2> ASYNC NEW_CORE C2115 name=collection1 org.apache.solr.core.SolrCore@67ec60b8
[junit4] 2> 926554 T2583 C2115 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:55076/solr/replication&command=fetchindex&wait=true} status=0 QTime=64
[junit4] 2> 926557 T2569 C2114 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> 926561 T2584 C2115 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> 926563 T2571 C2114 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> 926565 T2572 C2114 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> 926569 T2570 C2114 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> 926570 T2582 C2115 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> 926572 T2569 C2114 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> 926574 T2581 C2115 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> 926575 T2563 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4] 2> 926604 T2563 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=250405736
[junit4] 2> 926605 T2563 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@486858c4
[junit4] 2> 926606 T2563 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> 926607 T2563 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 926607 T2563 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 926608 T2563 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 926609 T2563 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 926609 T2563 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 926610 T2563 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-1374590203331/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-1374590203331/master/collection1/data/index;done=false>>]
[junit4] 2> 926610 T2563 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-1374590203331/master/collection1/data/index
[junit4] 2> 926611 T2563 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-1374590203331/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-1374590203331/master/collection1/data;done=false>>]
[junit4] 2> 926612 T2563 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-1374590203331/master/collection1/data
[junit4] 2> 926612 T2563 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 926687 T2563 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1376588860
[junit4] 2> 926688 T2563 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@67ec60b8
[junit4] 2> 926688 T2563 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> 926689 T2563 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 926690 T2563 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 926690 T2563 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 926691 T2563 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 926692 T2563 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 926692 T2563 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-1374590203683/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-1374590203683/slave/collection1/data;done=false>>]
[junit4] 2> 926693 T2563 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-1374590203683/slave/collection1/data
[junit4] 2> 926693 T2563 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-1374590203683/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-1374590203683/slave/collection1/data/index;done=false>>]
[junit4] 2> 926694 T2563 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-1374590203683/slave/collection1/data/index
[junit4] 2> 926695 T2563 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 926753 T2563 oas.SolrTestCaseJ4.setUp ###Starting testNoWriter
[junit4] 2> 926755 T2563 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 926757 T2563 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55609
[junit4] 2> 926758 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 926758 T2563 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 926758 T2563 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master
[junit4] 2> 926759 T2563 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/'
[junit4] 2> 926770 T2563 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-1374590204417/master/solr.xml
[junit4] 2> 926771 T2563 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/solr.xml does not exist, using default configuration
[junit4] 2> 926800 T2563 oasc.CoreContainer.<init> New CoreContainer 163761266
[junit4] 2> 926801 T2563 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/]
[junit4] 2> 926802 T2563 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 926802 T2563 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 926803 T2563 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 926803 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 926803 T2563 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 926803 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 926804 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 926804 T2563 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 926804 T2563 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 926805 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 926811 T2608 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/collection1
[junit4] 2> 926811 T2608 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/collection1/'
[junit4] 2> 926836 T2608 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 926862 T2608 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 926863 T2608 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 926866 T2608 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 926875 T2608 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 926876 T2608 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 926877 T2608 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204417/master/collection1/data/
[junit4] 2> 926877 T2608 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 926877 T2608 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-1374590204417/master/collection1/data
[junit4] 2> 926877 T2608 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-1374590204417/master/collection1/data/index/
[junit4] 2> 926878 T2608 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-1374590204417/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 926878 T2608 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-1374590204417/master/collection1/data/index
[junit4] 2> 926879 T2608 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@353201e6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@541d9b36; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> 926879 T2608 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 926880 T2608 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 926880 T2608 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 926881 T2608 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 926881 T2608 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 926881 T2608 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 926881 T2608 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 926883 T2608 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 926885 T2608 oass.SolrIndexSearcher.<init> Opening Searcher@759c3c19 main
[junit4] 2> 926886 T2608 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 926886 T2608 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 926886 T2608 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 926886 T2608 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 926886 T2608 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 926886 T2609 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@759c3c19 main{StandardDirectoryReader(segments_1:1)}
[junit4] 2> 926887 T2563 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 926887 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 926888 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 926892 T2563 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 926894 T2563 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59620
[junit4] 2> 926895 T2563 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 926895 T2563 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 926895 T2563 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave
[junit4] 2> 926896 T2563 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/'
[junit4] 2> 926906 T2563 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-1374590204554/slave/solr.xml
[junit4] 2> 926907 T2563 oasc.ConfigSolr.fromFile /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/solr.xml does not exist, using default configuration
[junit4] 2> 926942 T2563 oasc.CoreContainer.<init> New CoreContainer 1217110819
[junit4] 2> 926942 T2563 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/]
[junit4] 2> 926943 T2563 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4] 2> 926944 T2563 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 926944 T2563 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4] 2> 926944 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 926945 T2563 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 926945 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 926945 T2563 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 926945 T2563 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 926946 T2563 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 926946 T2563 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4] 2> 926971 T2620 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/collection1
[junit4] 2> 926971 T2620 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/collection1/'
[junit4] 2> 926997 T2620 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
[junit4] 2> 927024 T2620 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 927024 T2620 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 927028 T2620 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 927037 T2620 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 927038 T2620 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 927038 T2620 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590204554/slave/collection1/data/
[junit4] 2> 927039 T2620 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 927039 T2620 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-1374590204554/slave/collection1/data
[junit4] 2> 927039 T2620 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-1374590204554/slave/collection1/data/index/
[junit4] 2> 927040 T2620 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-1374590204554/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 927040 T2620 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-1374590204554/slave/collection1/data/index
[junit4] 2> 927041 T2620 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@330a3c4f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5e9f5c3f; maxCacheMB=0.890625 maxMergeSizeMB=0.1044921875)),segFN=segments_1,generation=1}
[junit4] 2> 927041 T2620 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 927042 T2620 oasc.Reque
[...truncated too long message...]
/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1374590268758/slave/collection1/data/index.20130723153751005 [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-1374590268758/slave/collection1/data/index.20130723153751005;done=true>>]
[junit4] 2> 993376 T3255 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-1374590268758/slave/collection1/data/index.20130723153751005
[junit4] 2> 993409 T3252 C2187 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=492 status=0 QTime=1
[junit4] 2> 993410 T2563 oas.SolrTestCaseJ4.tearDown ###Ending doTestReplicateAfterStartup
[junit4] 2> 993431 T2563 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=972287042
[junit4] 2> 993432 T2563 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@27ceaced
[junit4] 2> 993432 T2563 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=492,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 993433 T2563 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 993433 T2563 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 993433 T2563 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 993434 T2563 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 993435 T2563 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 993435 T2563 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-1374590268608/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-1374590268608/master/collection1/data;done=false>>]
[junit4] 2> 993435 T2563 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-1374590268608/master/collection1/data
[junit4] 2> 993436 T2563 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-1374590268608/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-1374590268608/master/collection1/data/index;done=false>>]
[junit4] 2> 993436 T2563 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-1374590268608/master/collection1/data/index
[junit4] 2> 993437 T2563 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 993508 T2563 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=496484934
[junit4] 2> 993509 T2563 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6bae7f6b
[junit4] 2> 993510 T2563 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> 993510 T2563 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 993510 T2563 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 993511 T2563 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 993511 T2563 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 993512 T2563 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 993512 T2563 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-1374590268758/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-1374590268758/slave/collection1/data/index;done=false>>]
[junit4] 2> 993513 T2563 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-1374590268758/slave/collection1/data/index
[junit4] 2> 993513 T2563 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-1374590268758/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-1374590268758/slave/collection1/data;done=false>>]
[junit4] 2> 993513 T2563 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-1374590268758/slave/collection1/data
[junit4] 2> 993514 T2563 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 993568 T2563 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene42: {newname=MockVariableIntBlock(baseBlockSize=115), id=MockVariableIntBlock(baseBlockSize=115), name=MockVariableIntBlock(baseBlockSize=115)}, docValues:{}, sim=DefaultSimilarity, locale=en_GB, timezone=Europe/London
[junit4] 2> NOTE: Linux 3.2.0-49-generic amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=8,threads=1,free=266146400,total=515899392
[junit4] 2> NOTE: All tests run in this JVM: [TestStressLucene, TestFastOutputStream, TestDynamicFieldResource, TimeZoneUtilsTest, TestCollationKeyRangeQueries, TestCloudManagedSchemaAddField, TestDFRSimilarityFactory, HighlighterConfigTest, TestPostingsSolrHighlighter, BasicZkTest, TestFiltering, TestSchemaSimilarityResource, TestComponentsName, TestIndexSearcher, DirectSolrSpellCheckerTest, SignatureUpdateProcessorFactoryTest, TestRandomFaceting, StatsComponentTest, SpellCheckComponentTest, CurrencyFieldXmlFileTest, TestDistributedSearch, DistanceFunctionTest, JSONWriterTest, TestBinaryResponseWriter, IndexSchemaRuntimeFieldTest, TestPropInject, DOMUtilTest, PathHierarchyTokenizerFactoryTest, RequiredFieldsTest, SampleTest, SuggesterTSTTest, TestSuggestSpellingConverter, ShardSplitTest, TestSchemaResource, FieldAnalysisRequestHandlerTest, TestCollationField, SuggesterWFSTTest, AssignTest, TestMergePolicyConfig, TestSolrJ, TestArbitraryIndexDir, HdfsSyncSliceTest, TestSolr4Spatial, OpenCloseCoreStressTest, TestSchemaVersionResource, SpellCheckCollatorTest, TermVectorComponentDistributedTest, MultiTermTest, SolrCoreCheckLockOnStartupTest, TestSerializedLuceneMatchVersion, TestBM25SimilarityFactory, CopyFieldTest, TestSolrXMLSerializer, BasicDistributedZk2Test, TestReloadAndDeleteDocs, HighlighterTest, OutputWriterTest, TestElisionMultitermQuery, DateMathParserTest, HdfsLockFactoryTest, TestManagedSchema, TestInfoStreamLogging, TestUpdate, DeleteShardTest, TestHashPartitioner, FullSolrCloudDistribCmdsTest, ZkNodePropsTest, CollectionsAPIDistributedZkTest, SolrIndexConfigTest, BadIndexSchemaTest, TestCodecSupport, LeaderElectionIntegrationTest, TestReplicationHandler]
[junit4] Completed on J1 in 67.93s, 14 tests, 1 failure <<< FAILURES!
[...truncated 460 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:1250: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:893: There were test failures: 319 suites, 1345 tests, 1 failure, 35 ignored (7 assumptions)
Total time: 41 minutes 15 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_25 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure