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 2014/05/18 12:33:32 UTC
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.7.0_55) - Build # 10213
- Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10213/
Java: 32bit/jdk1.7.0_55 -client -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestBackup
Error Message:
Stack Trace:
java.lang.NullPointerException
at __randomizedtesting.SeedInfo.seed([B6F66B3CA8174F2C:F77D4B598FA9BC63]:0)
at org.apache.solr.SolrTestCaseJ4.recurseDelete(SolrTestCaseJ4.java:1003)
at org.apache.solr.handler.TestReplicationHandler.doTestBackup(TestReplicationHandler.java:1553)
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:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11289 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/./solr.handler.TestReplicationHandler-B6F66B3CA8174F2C-001/init-core-data-001
[junit4] 2> 1018653 T4251 oas.SolrTestCaseJ4.setUp ###Starting testEmptyCommits
[junit4] 2> 1018657 T4251 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1018660 T4251 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44360
[junit4] 2> 1018661 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1018661 T4251 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1018662 T4251 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master
[junit4] 2> 1018663 T4251 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/'
[junit4] 2> 1018686 T4251 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/solr.xml
[junit4] 2> 1018732 T4251 oasc.CoreContainer.<init> New CoreContainer 30661068
[junit4] 2> 1018733 T4251 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/]
[junit4] 2> 1018734 T4251 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1018735 T4251 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1018735 T4251 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1018735 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1018736 T4251 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1018736 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1018737 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1018737 T4251 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1018737 T4251 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1018738 T4251 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1018738 T4251 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1018739 T4251 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1018743 T4261 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/'
[junit4] 2> 1018792 T4261 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1018837 T4261 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1018838 T4261 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1018842 T4261 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1018857 T4261 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1018858 T4261 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/
[junit4] 2> 1018859 T4261 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1018859 T4261 oasc.SolrCore.<init> [collection1] Opening new SolrCore at org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/
[junit4] 2> 1018859 T4261 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 1018860 T4261 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data
[junit4] 2> 1018860 T4261 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index/
[junit4] 2> 1018860 T4261 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1018861 T4261 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index
[junit4] 2> 1018861 T4261 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5883106361127791]
[junit4] 2> 1018862 T4261 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_1,generation=1}
[junit4] 2> 1018862 T4261 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1018863 T4261 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1018863 T4261 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1018864 T4261 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1018864 T4261 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1018864 T4261 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1018864 T4261 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1018865 T4261 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1018867 T4261 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1018870 T4261 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1018870 T4261 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1018871 T4261 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=31.611328125, floorSegmentMB=0.3359375, forceMergeDeletesPctAllowed=13.932247909626248, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1018872 T4261 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_1,generation=1}
[junit4] 2> 1018873 T4261 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1018873 T4261 oass.SolrIndexSearcher.<init> Opening Searcher@15c037[collection1] main
[junit4] 2> 1018874 T4261 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/conf
[junit4] 2> 1018875 T4261 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/conf/}
[junit4] 2> 1018875 T4261 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/conf
[junit4] 2> 1018876 T4261 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 1018876 T4261 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1018876 T4261 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1018877 T4261 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1018877 T4261 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1018877 T4261 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1018877 T4262 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15c037[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1018878 T4251 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1
[junit4] 2> 1018879 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1018884 T4251 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1018887 T4251 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46482
[junit4] 2> 1018889 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1018889 T4251 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1018890 T4251 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave
[junit4] 2> 1018891 T4251 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/'
[junit4] 2> 1018920 T4251 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/solr.xml
[junit4] 2> 1018984 T4251 oasc.CoreContainer.<init> New CoreContainer 25291458
[junit4] 2> 1018984 T4251 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/]
[junit4] 2> 1018986 T4251 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1018986 T4251 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1018986 T4251 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1018987 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1018987 T4251 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1018988 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1018988 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1018988 T4251 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1018989 T4251 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1018989 T4251 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1018990 T4251 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1018990 T4251 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1018994 T4273 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/'
[junit4] 2> 1019046 T4273 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1019093 T4273 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1019093 T4273 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1019098 T4273 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1019112 T4273 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1019113 T4273 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/
[junit4] 2> 1019113 T4273 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1019114 T4273 oasc.SolrCore.<init> [collection1] Opening new SolrCore at org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/
[junit4] 2> 1019114 T4273 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 1019114 T4273 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data
[junit4] 2> 1019115 T4273 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index/
[junit4] 2> 1019115 T4273 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1019115 T4273 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index
[junit4] 2> 1019116 T4273 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5883106361127791]
[junit4] 2> 1019116 T4273 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_1,generation=1}
[junit4] 2> 1019117 T4273 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1019118 T4273 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1019118 T4273 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1019119 T4273 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1019119 T4273 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1019119 T4273 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1019119 T4273 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1019120 T4273 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1019121 T4273 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1019123 T4273 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1019124 T4273 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1019124 T4273 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=31.611328125, floorSegmentMB=0.3359375, forceMergeDeletesPctAllowed=13.932247909626248, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1019125 T4273 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_1,generation=1}
[junit4] 2> 1019125 T4273 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1019125 T4273 oass.SolrIndexSearcher.<init> Opening Searcher@8388f6[collection1] main
[junit4] 2> 1019125 T4273 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/conf
[junit4] 2> 1019126 T4273 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/conf/}
[junit4] 2> 1019126 T4273 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/conf
[junit4] 2> 1019126 T4273 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 1019127 T4273 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1019127 T4273 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1019128 T4273 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 1019129 T4273 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1019129 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8388f6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1019129 T4251 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1
[junit4] 2> 1019130 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> ASYNC NEW_CORE C1141 name=collection1 org.apache.solr.core.SolrCore@1d6ed99
[junit4] 2> 1019132 T4258 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=*:*&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 1019136 T4259 C1141 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[1]} 0 1
[junit4] 2> 1019138 T4260 C1141 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1019139 T4260 C1141 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_2,generation=2}
[junit4] 2> 1019140 T4260 C1141 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 1019141 T4260 C1141 oass.SolrIndexSearcher.<init> Opening Searcher@f71324[collection1] main
[junit4] 2> 1019142 T4260 C1141 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1019142 T4262 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f71324[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(4.9):C1)}
[junit4] 2> 1019143 T4260 C1141 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&wt=javabin} {commit=} 0 5
[junit4] 2> 1019145 T4277 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1019145 T4277 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1019146 T4258 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0
[junit4] 2> 1019147 T4277 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 1019147 T4277 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4] 2> 1019148 T4277 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 1019153 T4259 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=filelist&generation=2&wt=javabin} status=0 QTime=3
[junit4] 2> 1019154 T4277 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4] 2> 1019155 T4277 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648228
[junit4] 2> 1019155 T4277 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 1019156 T4277 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 1019156 T4277 oasu.DefaultSolrCoreState.rollbackIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 1019157 T4277 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(RAMDirectory@86d877 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1e086c3) fullCopy=false
[junit4] 2> 1019159 T4260 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.fdt&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019163 T4257 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=segments_2&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019167 T4258 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.si&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019171 T4259 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.fnm&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019175 T4260 C1141 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.fdx&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> ASYNC NEW_CORE C1142 name=collection1 org.apache.solr.core.SolrCore@1d6ed99
[junit4] 2> 1019206 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.tip&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019209 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.tim&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019211 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.doc&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019214 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.nvm&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019217 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_0.nvd&command=filecontent&generation=2&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019218 T4277 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 1019219 T4277 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 1019220 T4277 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=27.9306640625, floorSegmentMB=1.1865234375, forceMergeDeletesPctAllowed=0.8234415893383684, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1019220 T4277 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_2,generation=2}
[junit4] 2> 1019221 T4277 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 1019221 T4277 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 1019222 T4277 oass.SolrIndexSearcher.<init> Opening Searcher@7908b5[collection1] main
[junit4] 2> 1019222 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7908b5[collection1] main{StandardDirectoryReader(segments_2:3:nrt _0(4.9):C1)}
[junit4] 2> 1019222 T4277 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648228 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648228;done=true>>]
[junit4] 2> 1019223 T4277 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648228
[junit4] 2> ASYNC NEW_CORE C1143 name=collection1 org.apache.solr.core.SolrCore@6fbc21
[junit4] 2> 1019223 T4269 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:44360/solr/replication} status=0 QTime=78
[junit4] 2> 1019226 T4270 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:empty1&wt=javabin} hits=1 status=0 QTime=1
[junit4] 2> 1019228 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=0
[junit4] 2> 1019230 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=0
[junit4] 2> 1019235 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&slave=false&command=details&wt=javabin} status=0 QTime=1
[junit4] 2> 1019236 T4271 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=4
[junit4] 2> 1019238 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=0
[junit4] 2> 1019240 T4272 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=1
[junit4] 2> 1019242 T4258 C1142 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1019243 T4258 C1142 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1019244 T4258 C1142 oasc.SolrCore.openNewSearcher SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 1019244 T4258 C1142 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1019244 T4258 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&wt=javabin} {commit=} 0 2
[junit4] 2> 1019245 T4280 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1019246 T4280 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1019248 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=1
[junit4] 2> 1019248 T4280 oash.SnapPuller.fetchLatestIndex Slave in sync with master.
[junit4] 2> 1019248 T4269 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:44360/solr/replication} status=0 QTime=3
[junit4] 2> 1019252 T4260 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[2]} 0 1
[junit4] 2> 1019254 T4257 C1142 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1019257 T4257 C1142 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_3,generation=3}
[junit4] 2> 1019258 T4257 C1142 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 1019258 T4257 C1142 oass.SolrIndexSearcher.<init> Opening Searcher@627c82[collection1] main
[junit4] 2> 1019259 T4257 C1142 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1019259 T4262 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@627c82[collection1] main{StandardDirectoryReader(segments_3:5:nrt _0(4.9):C1 _1(4.9):C1)}
[junit4] 2> 1019260 T4257 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&wt=javabin} {commit=} 0 6
[junit4] 2> 1019261 T4281 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1019261 T4281 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1019263 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0
[junit4] 2> 1019263 T4281 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 1019264 T4281 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 1019264 T4281 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 1019266 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=filelist&generation=3&wt=javabin} status=0 QTime=1
[junit4] 2> 1019266 T4281 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4] 2> 1019267 T4281 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648341
[junit4] 2> 1019267 T4281 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 1019267 T4281 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 1019268 T4281 oasu.DefaultSolrCoreState.rollbackIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 1019268 T4281 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(RAMDirectory@184a03f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@17af2e1) fullCopy=false
[junit4] 2> 1019268 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 1019268 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 1019269 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 1019269 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
[junit4] 2> 1019269 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 1019271 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.fnm&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019272 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 1019275 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.tim&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019309 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.nvm&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019312 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.fdx&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019315 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.fdt&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019316 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 1019319 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=segments_3&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019319 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
[junit4] 2> 1019320 T4281 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
[junit4] 2> 1019321 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.doc&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019324 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.si&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019327 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.tip&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019331 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_1.nvd&command=filecontent&generation=3&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019332 T4281 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 1019335 T4281 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 1019335 T4281 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=27.9306640625, floorSegmentMB=1.1865234375, forceMergeDeletesPctAllowed=0.8234415893383684, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1019337 T4281 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_3,generation=3}
[junit4] 2> 1019338 T4281 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 1019338 T4281 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 1019340 T4281 oass.SolrIndexSearcher.<init> Opening Searcher@2cae7a[collection1] main
[junit4] 2> 1019340 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2cae7a[collection1] main{StandardDirectoryReader(segments_3:5:nrt _0(4.9):C1 _1(4.9):C1)}
[junit4] 2> 1019341 T4281 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648341 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648341;done=true>>]
[junit4] 2> 1019341 T4281 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648341
[junit4] 2> 1019342 T4270 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:44360/solr/replication} status=0 QTime=81
[junit4] 2> 1019345 T4272 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:empty2&wt=javabin} hits=1 status=0 QTime=0
[junit4] 2> 1019348 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=0
[junit4] 2> 1019351 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=1
[junit4] 2> 1019356 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&slave=false&command=details&wt=javabin} status=0 QTime=0
[junit4] 2> 1019357 T4270 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=4
[junit4] 2> 1019360 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=0
[junit4] 2> 1019362 T4271 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=0
[junit4] 2> 1019366 T4258 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[3]} 0 1
[junit4] 2> 1019368 T4259 C1142 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1019372 T4259 C1142 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_4,generation=4}
[junit4] 2> 1019373 T4259 C1142 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 1019375 T4259 C1142 oass.SolrIndexSearcher.<init> Opening Searcher@19565b8[collection1] realtime
[junit4] 2> 1019376 T4259 C1142 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1019376 T4259 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&openSearcher=false&commit=true&wt=javabin} {commit=} 0 8
[junit4] 2> 1019377 T4283 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1019378 T4283 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1019380 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0
[junit4] 2> 1019381 T4283 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4] 2> 1019381 T4283 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 1019382 T4283 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 1019385 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=filelist&generation=4&wt=javabin} status=0 QTime=1
[junit4] 2> 1019386 T4283 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4] 2> 1019387 T4283 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648460
[junit4] 2> 1019388 T4283 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 1019388 T4283 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 1019389 T4283 oasu.DefaultSolrCoreState.rollbackIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 1019389 T4283 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(RAMDirectory@8ae3dc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@11d25bb) fullCopy=false
[junit4] 2> 1019390 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 1019390 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 1019390 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
[junit4] 2> 1019393 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.fnm&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019395 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 1019398 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.tip&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019399 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 1019399 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4] 2> 1019402 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.fdt&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019403 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 1019406 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.doc&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019408 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 1019408 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
[junit4] 2> 1019409 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
[junit4] 2> 1019409 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 1019409 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.doc because it already exists
[junit4] 2> 1019410 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tip because it already exists
[junit4] 2> 1019410 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4] 2> 1019413 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.fdx&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019414 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 1019417 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.nvm&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019421 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.tim&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019423 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 1019423 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tim because it already exists
[junit4] 2> 1019426 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=segments_4&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019430 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.si&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019432 T4283 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 1019434 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_2.nvd&command=filecontent&generation=4&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019436 T4283 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 1019438 T4283 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 1019439 T4283 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=27.9306640625, floorSegmentMB=1.1865234375, forceMergeDeletesPctAllowed=0.8234415893383684, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1019441 T4283 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=3
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_4,generation=4}
[junit4] 2> 1019442 T4283 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 1019442 T4283 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 1019444 T4283 oass.SolrIndexSearcher.<init> Opening Searcher@da486b[collection1] main
[junit4] 2> 1019445 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da486b[collection1] main{StandardDirectoryReader(segments_4:7:nrt _0(4.9):C1 _1(4.9):C1 _2(4.9):C1)}
[junit4] 2> 1019445 T4283 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648460 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648460;done=true>>]
[junit4] 2> 1019446 T4283 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648460
[junit4] 2> 1019447 T4269 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:44360/solr/replication} status=0 QTime=70
[junit4] 2> 1019450 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:empty3&wt=javabin} hits=0 status=0 QTime=1
[junit4] 2> 1019453 T4272 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:empty3&wt=javabin} hits=1 status=0 QTime=1
[junit4] 2> 1019456 T4257 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&wt=javabin} {add=[4]} 0 0
[junit4] 2> 1019459 T4258 C1142 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1019462 T4258 C1142 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=4
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@a2233e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@172a6c0),segFN=segments_5,generation=5}
[junit4] 2> 1019463 T4258 C1142 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 1019465 T4258 C1142 oass.SolrIndexSearcher.<init> Opening Searcher@4c3b90[collection1] main
[junit4] 2> 1019466 T4258 C1142 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 1019466 T4262 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c3b90[collection1] main{StandardDirectoryReader(segments_5:9:nrt _0(4.9):C1 _1(4.9):C1 _2(4.9):C1 _3(4.9):C1)}
[junit4] 2> 1019467 T4258 C1142 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={version=2&commit=true&wt=javabin} {commit=} 0 8
[junit4] 2> 1019469 T4285 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1019470 T4285 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 1019472 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin} status=0 QTime=0
[junit4] 2> 1019473 T4285 oash.SnapPuller.fetchLatestIndex Master's generation: 5
[junit4] 2> 1019474 T4285 oash.SnapPuller.fetchLatestIndex Slave's generation: 4
[junit4] 2> 1019474 T4285 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 1019477 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=filelist&generation=5&wt=javabin} status=0 QTime=1
[junit4] 2> 1019478 T4285 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 37
[junit4] 2> 1019479 T4285 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648552
[junit4] 2> 1019481 T4285 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 1019482 T4285 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 1019482 T4285 oasu.DefaultSolrCoreState.rollbackIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 1019483 T4285 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(RAMDirectory@179092c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10b39a9) fullCopy=false
[junit4] 2> 1019484 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 1019484 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 1019485 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tim because it already exists
[junit4] 2> 1019487 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.nvm&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019489 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fnm because it already exists
[junit4] 2> 1019490 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 1019490 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.tip because it already exists
[junit4] 2> 1019491 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 1019491 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4] 2> 1019491 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdt because it already exists
[junit4] 2> 1019492 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 1019494 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.si&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019496 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.doc because it already exists
[junit4] 2> 1019496 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 1019499 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.nvd&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019501 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.tip because it already exists
[junit4] 2> 1019501 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.doc because it already exists
[junit4] 2> 1019501 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 1019502 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.doc because it already exists
[junit4] 2> 1019505 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.fdx&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=1
[junit4] 2> 1019506 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tip because it already exists
[junit4] 2> 1019507 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4] 2> 1019509 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=segments_5&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019511 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.fdx because it already exists
[junit4] 2> 1019514 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.fdt&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019515 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 1019516 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvm because it already exists
[junit4] 2> 1019516 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.tim because it already exists
[junit4] 2> 1019519 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.tim&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019521 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 1019521 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _1.tim because it already exists
[junit4] 2> 1019521 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.si because it already exists
[junit4] 2> 1019524 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.doc&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019526 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 1019528 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.tip&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019530 T4285 oash.SnapPuller.downloadIndexFiles Skipping download for _2.nvd because it already exists
[junit4] 2> 1019533 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&file=_3.fnm&command=filecontent&generation=5&wt=filestream&checksum=true} status=0 QTime=0
[junit4] 2> 1019534 T4285 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 1019538 T4285 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 1019538 T4285 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=39, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=27.9306640625, floorSegmentMB=1.1865234375, forceMergeDeletesPctAllowed=0.8234415893383684, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 1019542 T4285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=4
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_4,generation=4}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1c1b6a9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bb3c15),segFN=segments_5,generation=5}
[junit4] 2> 1019542 T4285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4] 2> 1019543 T4285 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 1019546 T4285 oass.SolrIndexSearcher.<init> Opening Searcher@16ec680[collection1] main
[junit4] 2> 1019547 T4274 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16ec680[collection1] main{StandardDirectoryReader(segments_5:9:nrt _0(4.9):C1 _1(4.9):C1 _2(4.9):C1 _3(4.9):C1)}
[junit4] 2> 1019547 T4285 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648552 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648552;done=true>>]
[junit4] 2> 1019548 T4285 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index.20140518101648552
[junit4] 2> 1019549 T4270 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:44360/solr/replication} status=0 QTime=80
[junit4] 2> 1019553 T4259 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:(empty1+empty2+empty3+empty4)&wt=javabin} hits=4 status=0 QTime=1
[junit4] 2> 1019556 T4271 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&version=2&q=name:(empty1+empty2+empty3+empty4)&wt=javabin} hits=4 status=0 QTime=1
[junit4] 2> 1019560 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=1
[junit4] 2> 1019563 T4258 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=1
[junit4] 2> 1019568 T4260 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&slave=false&command=details&wt=javabin} status=0 QTime=0
[junit4] 2> 1019569 T4269 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=details&wt=javabin&_trace=getDetails} status=0 QTime=3
[junit4] 2> 1019572 T4257 C1142 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=0
[junit4] 2> 1019575 T4272 C1143 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={qt=/replication&version=2&command=indexversion&wt=javabin&_trace=assertVersions} status=0 QTime=0
[junit4] 2> 1019576 T4251 oas.SolrTestCaseJ4.tearDown ###Ending testEmptyCommits
[junit4] 2> 1019598 T4251 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=30661068
[junit4] 2> 1019599 T4251 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1d6ed99
[junit4] 2> 1019600 T4251 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> 1019601 T4251 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1019602 T4251 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1019603 T4251 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1019604 T4251 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1019605 T4251 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1019606 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index;done=false>>]
[junit4] 2> 1019606 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data/index
[junit4] 2> 1019607 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data;done=false>>]
[junit4] 2> 1019608 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207728/master/collection1/data
[junit4] 2> 1019610 T4251 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1019682 T4251 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=25291458
[junit4] 2> 1019683 T4251 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6fbc21
[junit4] 2> 1019684 T4251 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> 1019685 T4251 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1019686 T4251 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1019687 T4251 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1019689 T4251 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1019690 T4251 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1019690 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index;done=false>>]
[junit4] 2> 1019691 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data/index
[junit4] 2> 1019692 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data;done=false>>]
[junit4] 2> 1019693 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408207953/slave/collection1/data
[junit4] 2> 1019694 T4251 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1019759 T4251 oas.SolrTestCaseJ4.setUp ###Starting doTestStopPoll
[junit4] 2> 1019762 T4251 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1019764 T4251 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44973
[junit4] 2> 1019765 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1019765 T4251 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1019766 T4251 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master
[junit4] 2> 1019766 T4251 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/'
[junit4] 2> 1019783 T4251 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/solr.xml
[junit4] 2> 1019828 T4251 oasc.CoreContainer.<init> New CoreContainer 21152062
[junit4] 2> 1019829 T4251 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/]
[junit4] 2> 1019830 T4251 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1019831 T4251 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1019831 T4251 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1019831 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1019832 T4251 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1019832 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1019832 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1019833 T4251 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1019833 T4251 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1019834 T4251 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1019834 T4251 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1019834 T4251 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1019838 T4296 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/'
[junit4] 2> 1019890 T4296 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1019933 T4296 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1019934 T4296 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1019938 T4296 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1019951 T4296 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1019952 T4296 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/
[junit4] 2> 1019953 T4296 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1019953 T4296 oasc.SolrCore.<init> [collection1] Opening new SolrCore at org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/data/
[junit4] 2> 1019953 T4296 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 1019954 T4296 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/data
[junit4] 2> 1019954 T4296 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/data/index/
[junit4] 2> 1019954 T4296 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 1019955 T4296 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/data/index
[junit4] 2> 1019955 T4296 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=44, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5883106361127791]
[junit4] 2> 1019956 T4296 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1613277 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ceecc5),segFN=segments_1,generation=1}
[junit4] 2> 1019956 T4296 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1019957 T4296 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1019958 T4296 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1019958 T4296 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1019958 T4296 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 1019958 T4296 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 1019959 T4296 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 1019959 T4296 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1019961 T4296 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1019964 T4296 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1019964 T4296 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1019964 T4296 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=31.611328125, floorSegmentMB=0.3359375, forceMergeDeletesPctAllowed=13.932247909626248, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1019965 T4296 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@1613277 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ceecc5),segFN=segments_1,generation=1}
[junit4] 2> 1019965 T4296 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1019965 T4296 oass.SolrIndexSearcher.<init> Opening Searcher@322311[collection1] main
[junit4] 2> 1019966 T4296 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/conf
[junit4] 2> 1019966 T4296 oasr.RestManager.init Initializing RestManager with initArgs: {storageDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/conf/}
[junit4] 2> 1019966 T4296 oasr.ManagedResourceStorage.load Reading _rest_managed.json using file:dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408208833/master/collection1/conf
[junit4] 2> 1019966 T4296 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
[junit4] 2> 1019967 T4296 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 1019967 T4296 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 1019967 T4296 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1019967 T4296 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 1019968 T4296 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1019968 T4297 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@322311[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1019968 T4251 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1
[junit4] 2> 1019969 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1019972 T4251 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1019976 T4251 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49100
[junit4] 2> 1019978 T4251 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1019978 T4251 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1019979 T4251 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave
[junit4] 2> 1019980 T4251 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave/'
[junit4] 2> 1020001 T4251 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave/solr.xml
[junit4] 2> 1020044 T4251 oasc.CoreContainer.<init> New CoreContainer 21893838
[junit4] 2> 1020045 T4251 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave/]
[junit4] 2> 1020046 T4251 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 1020047 T4251 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 1020047 T4251 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1020047 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1020048 T4251 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1020048 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1020048 T4251 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1020049 T4251 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1020049 T4251 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1020050 T4251 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1020050 T4251 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1020050 T4251 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 1020054 T4308 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave/collection1/'
[junit4] 2> 1020104 T4308 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
[junit4] 2> 1020145 T4308 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1020146 T4308 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1020150 T4308 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1020163 T4308 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1020164 T4308 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408209044/slave/collection1/
[junit4] 2> 1020165 T4308 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[j
[...truncated too long message...]
oasc.CoreContainer.shutdown Shutting down CoreContainer instance=21573953
[junit4] 2> 1064055 T4251 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1c15ea5
[junit4] 2> 1064056 T4251 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> 1064056 T4251 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1064056 T4251 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1064057 T4251 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1064057 T4251 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1064058 T4251 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1064058 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data/index;done=false>>]
[junit4] 2> 1064059 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data/index
[junit4] 2> 1064059 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data;done=false>>]
[junit4] 2> 1064059 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249493/master/collection1/data
[junit4] 2> 1064060 T4251 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1064132 T4251 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=7658785
[junit4] 2> 1064133 T4251 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@f89446
[junit4] 2> 1064133 T4251 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> 1064134 T4251 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 1064134 T4251 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1064134 T4251 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1064135 T4251 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 1064135 T4251 oasc.CachingDirectoryFactory.close Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1064136 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data/index;done=false>>]
[junit4] 2> 1064136 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data/index
[junit4] 2> 1064136 T4251 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data;done=false>>]
[junit4] 2> 1064137 T4251 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/org.apache.solr.handler.TestReplicationHandler$SolrInstance-1400408249760/slave/collection1/data
[junit4] 2> 1064137 T4251 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 1064197 T4251 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J1/./solr.handler.TestReplicationHandler-B6F66B3CA8174F2C-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene46), sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=sq, timezone=Iceland
[junit4] 2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.7.0_55 (32-bit)/cpus=8,threads=1,free=230202720,total=349175808
[junit4] 2> NOTE: All tests run in this JVM: [MultiTermTest, TestIBSimilarityFactory, PathHierarchyTokenizerFactoryTest, TestCodecSupport, TestQueryTypes, SolrPluginUtilsTest, FieldAnalysisRequestHandlerTest, DocValuesMultiTest, RequiredFieldsTest, TestWordDelimiterFilterFactory, TestFieldTypeCollectionResource, ShardSplitTest, HdfsDirectoryTest, TestStressRecovery, TestSearcherReuse, TestSimpleQParserPlugin, TestInfoStreamLogging, TestSolr4Spatial, FullSolrCloudDistribCmdsTest, IndexBasedSpellCheckerTest, TestRandomFaceting, HdfsBasicDistributedZkTest, SolrIndexConfigTest, TestSolrXmlPersistor, StandardRequestHandlerTest, PingRequestHandlerTest, IndexSchemaRuntimeFieldTest, DefaultValueUpdateProcessorTest, TestUpdate, RAMDirectoryFactoryTest, ChaosMonkeySafeLeaderTest, TestDistributedSearch, CollectionsAPIDistributedZkTest, SortByFunctionTest, SuggestComponentTest, TestHashPartitioner, SolrRequestParserTest, CachingDirectoryFactoryTest, MigrateRouteKeyTest, CurrencyFieldXmlFileTest, TestRangeQuery, OpenCloseCoreStressTest, TestNoOpRegenerator, TestCollationField, HighlighterTest, TestSweetSpotSimilarityFactory, TestStressUserVersions, ChaosMonkeyNothingIsSafeTest, TestFreeTextSuggestions, TestAtomicUpdateErrorCases, QueryResultKeyTest, TestOverriddenPrefixQueryForCustomFieldType, TestFuzzyAnalyzedSuggestions, TestNumberUtils, TestHighlightDedupGrouping, TestFieldTypeResource, TestOmitPositions, TestDistributedGrouping, TestPartialUpdateDeduplication, DebugComponentTest, ChangedSchemaMergeTest, TestIndexSearcher, SpellingQueryConverterTest, TestStressReorder, ZkSolrClientTest, OpenExchangeRatesOrgProviderTest, CoreAdminRequestStatusTest, TestCustomSort, DirectSolrSpellCheckerTest, TestManagedResource, PreAnalyzedUpdateProcessorTest, TestPhraseSuggestions, TestBlendedInfixSuggestions, TestDistributedMissingSort, TestDefaultSearchFieldResource, TestManagedSchema, SignatureUpdateProcessorFactoryTest, TestUtils, SuggesterTSTTest, TestDocBasedVersionConstraints, AnalysisErrorHandlingTest, TestCSVResponseWriter, PrimUtilsTest, TestSchemaSimilarityResource, AlternateDirectoryTest, TestCSVLoader, TestSolrQueryParserResource, TestSolrXml, TestSolrCoreProperties, TestManagedSchemaFieldResource, TestNonDefinedSimilarityFactory, BadIndexSchemaTest, TestDynamicFieldResource, TestAnalyzeInfixSuggestions, MinimalSchemaTest, HdfsBasicDistributedZk2Test, CursorPagingTest, BasicDistributedZk2Test, OverseerTest, ShardRoutingTest, TestReplicationHandler]
[junit4] Completed on J1 in 45.58s, 14 tests, 1 error <<< FAILURES!
[...truncated 594 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/lucene/common-build.xml:1297: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/lucene/common-build.xml:921: There were test failures: 393 suites, 1637 tests, 1 error, 37 ignored (16 assumptions)
Total time: 75 minutes 7 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_55 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure