You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/03 03:43:24 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b106) - Build #
7620 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7620/
Java: 64bit/jdk1.8.0-ea-b106 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Wed Oct 02 22:35:39 ART 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Wed Oct 02 22:35:39 ART 2013
at __randomizedtesting.SeedInfo.seed([581E7CF0587C0D3D:AF6D92A89E94A2DB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1514)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1263)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10329 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> 560981 T2844 oas.SolrTestCaseJ4.setUp ###Starting doTestDetails
[junit4] 2> 560985 T2844 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 560990 T2844 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34669
[junit4] 2> 560991 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 560991 T2844 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 560991 T2844 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master
[junit4] 2> 560992 T2844 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/'
[junit4] 2> 561000 T2844 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/solr.xml
[junit4] 2> 561007 T2844 oasc.CoreContainer.<init> New CoreContainer 1292930659
[junit4] 2> 561008 T2844 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/]
[junit4] 2> 561008 T2844 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 561008 T2844 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 561009 T2844 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 561010 T2844 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 561010 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 561011 T2844 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 561011 T2844 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 561013 T2854 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1
[junit4] 2> 561013 T2854 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/'
[junit4] 2> 561026 T2854 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 561044 T2854 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 561046 T2854 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 561047 T2854 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561050 T2854 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561050 T2854 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 561050 T2854 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/
[junit4] 2> 561051 T2854 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 561051 T2854 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data
[junit4] 2> 561051 T2854 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index/
[junit4] 2> 561051 T2854 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 561051 T2854 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index
[junit4] 2> 561052 T2854 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=85.9326171875, floorSegmentMB=0.5556640625, forceMergeDeletesPctAllowed=20.08281099448092, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.419057191051459
[junit4] 2> 561052 T2854 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_1,generation=1}
[junit4] 2> 561052 T2854 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561053 T2854 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 561053 T2854 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 561053 T2854 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 561053 T2854 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 561053 T2854 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 561053 T2854 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 561054 T2854 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 561055 T2854 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 561055 T2854 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 561056 T2854 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 561056 T2854 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1261068733, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 561057 T2854 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_1,generation=1}
[junit4] 2> 561057 T2854 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561057 T2854 oass.SolrIndexSearcher.<init> Opening Searcher@3417272b main
[junit4] 2> 561057 T2854 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 561058 T2854 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 561058 T2854 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 561058 T2855 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3417272b main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 561058 T2844 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 561059 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 561059 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 561062 T2844 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 561064 T2844 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41408
[junit4] 2> 561064 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 561065 T2844 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 561065 T2844 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave
[junit4] 2> 561065 T2844 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/'
[junit4] 2> 561073 T2844 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/solr.xml
[junit4] 2> 561080 T2844 oasc.CoreContainer.<init> New CoreContainer 537622379
[junit4] 2> 561080 T2844 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/]
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 561081 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 561082 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 561082 T2844 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 561082 T2844 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 561082 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 561083 T2844 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 561083 T2844 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 561084 T2866 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1
[junit4] 2> 561085 T2866 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/'
[junit4] 2> 561096 T2866 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 561104 T2866 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 561104 T2866 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 561106 T2866 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561109 T2866 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561109 T2866 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 561109 T2866 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/
[junit4] 2> 561109 T2866 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 561110 T2866 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data
[junit4] 2> 561110 T2866 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index/
[junit4] 2> 561110 T2866 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 561110 T2866 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index
[junit4] 2> 561110 T2866 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=85.9326171875, floorSegmentMB=0.5556640625, forceMergeDeletesPctAllowed=20.08281099448092, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.419057191051459
[junit4] 2> 561111 T2866 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_1,generation=1}
[junit4] 2> 561111 T2866 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561112 T2866 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 561112 T2866 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 561113 T2866 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 561114 T2866 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 561114 T2866 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 561115 T2866 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1261068733, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 561115 T2866 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_1,generation=1}
[junit4] 2> 561115 T2866 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561115 T2866 oass.SolrIndexSearcher.<init> Opening Searcher@5558fcb8 main
[junit4] 2> 561116 T2866 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 561116 T2867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5558fcb8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 561116 T2866 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 561117 T2844 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 561117 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 561117 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C729 name=collection1 org.apache.solr.core.SolrCore@67de7984
[junit4] 2> 561123 T2850 C729 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=3
[junit4] 2> 561125 T2851 C729 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 561129 T2852 C729 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C730 name=collection1 org.apache.solr.core.SolrCore@58c7cc5
[junit4] 2> 561130 T2862 C730 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 561132 T2853 C729 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[0]} 0 0
[junit4] 2> 561134 T2850 C729 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 561136 T2850 C729 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_2,generation=2}
[junit4] 2> 561137 T2850 C729 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 561138 T2850 C729 oass.SolrIndexSearcher.<init> Opening Searcher@54e10e64 main
[junit4] 2> 561139 T2850 C729 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 561139 T2855 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54e10e64 main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):C1)}
[junit4] 2> 561139 T2850 C729 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 5
[junit4] 2> 561141 T2870 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 561141 T2870 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 561143 T2851 C729 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 561143 T2870 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4] 2> 561143 T2870 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4] 2> 561143 T2870 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 561146 T2852 C729 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4] 2> 561146 T2870 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 10
[junit4] 2> 561147 T2870 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519560
[junit4] 2> 561153 T2870 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5912479c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@629890a7) fullCopy=false
[junit4] 2> ASYNC NEW_CORE C731 name=collection1 org.apache.solr.core.SolrCore@67de7984
[junit4] 2> 561155 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_NestedPulsing_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561157 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561160 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561162 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561164 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561167 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4] 2> 561169 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_NestedPulsing_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561171 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561174 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561176 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_0_NestedPulsing_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4] 2> 561177 T2870 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 561177 T2870 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 561178 T2870 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 561178 T2870 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 561178 T2870 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 561178 T2870 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=75.51953125, floorSegmentMB=1.3857421875, forceMergeDeletesPctAllowed=11.534108456668472, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 561179 T2870 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_2,generation=2}
[junit4] 2> 561179 T2870 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4] 2> 561179 T2870 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 561179 T2870 oass.SolrIndexSearcher.<init> Opening Searcher@54fccd5b main
[junit4] 2> 561180 T2867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54fccd5b main{StandardDirectoryReader(segments_2:3:nrt _0(4.6):C1)}
[junit4] 2> 561180 T2870 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519560 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519560;done=true>>]
[junit4] 2> 561180 T2870 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519560
[junit4] 2> ASYNC NEW_CORE C732 name=collection1 org.apache.solr.core.SolrCore@58c7cc5
[junit4] 2> 561180 T2863 C732 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:34669/solr/replication&command=fetchindex&wait=true} status=0 QTime=40
[junit4] 2> 561185 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 561185 T2864 C732 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 561188 T2852 C731 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[1]} 0 1
[junit4] 2> 561190 T2853 C731 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 561192 T2853 C731 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_3,generation=3}
[junit4] 2> 561192 T2853 C731 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 561193 T2853 C731 oass.SolrIndexSearcher.<init> Opening Searcher@44314940 main
[junit4] 2> 561193 T2853 C731 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 561193 T2855 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@44314940 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):C1 _1(4.6):C1)}
[junit4] 2> 561193 T2853 C731 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 3
[junit4] 2> 561194 T2873 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 561195 T2873 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 561196 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 561197 T2873 oash.SnapPuller.fetchLatestIndex Master's generation: 3
[junit4] 2> 561197 T2873 oash.SnapPuller.fetchLatestIndex Slave's generation: 2
[junit4] 2> 561197 T2873 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 561199 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=3&version=2} status=0 QTime=1
[junit4] 2> 561199 T2873 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 19
[junit4] 2> 561200 T2873 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519614
[junit4] 2> 561200 T2873 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2faabd17 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@258beaa3) fullCopy=false
[junit4] 2> 561202 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_NestedPulsing_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561203 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.doc because it already exists
[junit4] 2> 561204 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561205 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 561207 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561207 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.tip because it already exists
[junit4] 2> 561207 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 561209 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561210 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.tim because it already exists
[junit4] 2> 561212 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_NestedPulsing_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561214 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561216 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561218 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561219 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 561219 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 561219 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 561221 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_1_NestedPulsing_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561221 T2873 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 561223 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_3&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=3} status=0 QTime=0
[junit4] 2> 561224 T2873 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 561225 T2873 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 561225 T2873 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 561225 T2873 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 561226 T2873 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 561226 T2873 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=75.51953125, floorSegmentMB=1.3857421875, forceMergeDeletesPctAllowed=11.534108456668472, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 561227 T2873 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_3,generation=3}
[junit4] 2> 561227 T2873 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4] 2> 561227 T2873 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 561228 T2873 oass.SolrIndexSearcher.<init> Opening Searcher@5bcd7611 main
[junit4] 2> 561228 T2867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5bcd7611 main{StandardDirectoryReader(segments_3:5:nrt _0(4.6):C1 _1(4.6):C1)}
[junit4] 2> 561229 T2873 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519614 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519614;done=true>>]
[junit4] 2> 561229 T2873 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519614
[junit4] 2> 561229 T2865 C732 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:34669/solr/replication&command=fetchindex&wait=true} status=0 QTime=35
[junit4] 2> 561233 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> 561234 T2862 C732 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 561236 T2851 C731 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={wt=javabin&version=2} {add=[2]} 0 1
[junit4] 2> 561237 T2852 C731 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 561239 T2852 C731 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@615c3748 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26bc324e),segFN=segments_4,generation=4}
[junit4] 2> 561239 T2852 C731 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 561240 T2852 C731 oass.SolrIndexSearcher.<init> Opening Searcher@7427daec main
[junit4] 2> 561240 T2852 C731 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 561240 T2855 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7427daec main{StandardDirectoryReader(segments_4:7:nrt _0(4.6):C1 _1(4.6):C1 _2(4.6):C1)}
[junit4] 2> 561241 T2852 C731 oasup.LogUpdateProcessor.finish [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 4
[junit4] 2> 561242 T2875 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 561242 T2875 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 561244 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 561244 T2875 oash.SnapPuller.fetchLatestIndex Master's generation: 4
[junit4] 2> 561244 T2875 oash.SnapPuller.fetchLatestIndex Slave's generation: 3
[junit4] 2> 561244 T2875 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4] 2> 561246 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=4&version=2} status=0 QTime=0
[junit4] 2> 561247 T2875 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 28
[junit4] 2> 561247 T2875 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519661
[junit4] 2> 561247 T2875 oash.SnapPuller.fetchLatestIndex Starting download to MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@3574fa45 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@57435caf) fullCopy=false
[junit4] 2> 561249 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561251 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_NestedPulsing_0.tim&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1_NestedPulsing_0.tip because it already exists
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.tip because it already exists
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fnm because it already exists
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.tim because it already exists
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1_NestedPulsing_0.doc because it already exists
[junit4] 2> 561252 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvd because it already exists
[junit4] 2> 561253 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1_NestedPulsing_0.tim because it already exists
[junit4] 2> 561253 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.si because it already exists
[junit4] 2> 561254 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_NestedPulsing_0.tip&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561255 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0_NestedPulsing_0.doc because it already exists
[junit4] 2> 561255 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvm because it already exists
[junit4] 2> 561255 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fnm because it already exists
[junit4] 2> 561255 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.nvd because it already exists
[junit4] 2> 561257 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdt&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561258 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.nvm because it already exists
[junit4] 2> 561259 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fdx&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561261 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.fnm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561262 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdx because it already exists
[junit4] 2> 561264 T2853 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvm&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561265 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.fdt because it already exists
[junit4] 2> 561265 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _1.si because it already exists
[junit4] 2> 561266 T2850 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2.nvd&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561267 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdx because it already exists
[junit4] 2> 561267 T2875 oash.SnapPuller.downloadIndexFiles Skipping download for _0.fdt because it already exists
[junit4] 2> 561269 T2851 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=segments_4&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561271 T2852 C731 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={file=_2_NestedPulsing_0.doc&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=4} status=0 QTime=0
[junit4] 2> 561272 T2875 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4] 2> 561272 T2875 oasu.DefaultSolrCoreState.closeIndexWriter Closing IndexWriter...
[junit4] 2> 561272 T2875 oasu.DefaultSolrCoreState.closeIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4] 2> 561273 T2875 oasu.DefaultSolrCoreState.closeIndexWriter Rollback old IndexWriter... core=collection1
[junit4] 2> 561274 T2875 oasu.DefaultSolrCoreState.openIndexWriter Creating new IndexWriter...
[junit4] 2> 561275 T2875 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=10, maxMergedSegmentMB=75.51953125, floorSegmentMB=1.3857421875, forceMergeDeletesPctAllowed=11.534108456668472, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 561276 T2875 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2c18530e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f5d3f22),segFN=segments_4,generation=4}
[junit4] 2> 561276 T2875 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4] 2> 561276 T2875 oasu.DefaultSolrCoreState.openIndexWriter New IndexWriter is ready to be used.
[junit4] 2> 561277 T2875 oass.SolrIndexSearcher.<init> Opening Searcher@332bbf9b main
[junit4] 2> 561277 T2867 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@332bbf9b main{StandardDirectoryReader(segments_4:7:nrt _0(4.6):C1 _1(4.6):C1 _2(4.6):C1)}
[junit4] 2> 561277 T2875 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519661 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519661;done=true>>]
[junit4] 2> 561277 T2875 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index.20131002223519661
[junit4] 2> 561278 T2863 C732 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={masterUrl=http://127.0.0.1:34669/solr/replication&command=fetchindex&wait=true} status=0 QTime=36
[junit4] 2> 561282 T2844 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 561284 T2844 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48042
[junit4] 2> 561285 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 561285 T2844 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 561285 T2844 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater
[junit4] 2> 561286 T2844 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/'
[junit4] 2> 561294 T2844 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/solr.xml
[junit4] 2> 561300 T2844 oasc.CoreContainer.<init> New CoreContainer 2076918884
[junit4] 2> 561300 T2844 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/]
[junit4] 2> 561305 T2844 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 561305 T2844 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 561306 T2844 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 561306 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 561306 T2844 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 561306 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 561306 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 561307 T2844 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 561307 T2844 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 561307 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 561308 T2844 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 561308 T2844 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 561309 T2886 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1
[junit4] 2> 561309 T2886 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/'
[junit4] 2> 561321 T2886 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 561327 T2886 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 561328 T2886 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 561330 T2886 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561332 T2886 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561332 T2886 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 561332 T2886 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/
[junit4] 2> 561332 T2886 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 561333 T2886 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data
[junit4] 2> 561333 T2886 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index/
[junit4] 2> 561333 T2886 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 561333 T2886 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index
[junit4] 2> 561333 T2886 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=85.9326171875, floorSegmentMB=0.5556640625, forceMergeDeletesPctAllowed=20.08281099448092, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.419057191051459
[junit4] 2> 561334 T2886 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7748057 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1907edfb),segFN=segments_1,generation=1}
[junit4] 2> 561334 T2886 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561334 T2886 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 561335 T2886 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 561336 T2886 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 561337 T2886 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 561337 T2886 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 561337 T2886 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1261068733, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 561337 T2886 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7748057 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1907edfb),segFN=segments_1,generation=1}
[junit4] 2> 561337 T2886 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561338 T2886 oass.SolrIndexSearcher.<init> Opening Searcher@3c2e9671 main
[junit4] 2> 561338 T2886 oash.SnapPuller.<init> WARN 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 561338 T2886 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 561338 T2886 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml
[junit4] 2> 561338 T2886 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 561338 T2887 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c2e9671 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 561338 T2886 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 561339 T2844 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 561339 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 561339 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C733 name=collection1 org.apache.solr.core.SolrCore@67de7984
[junit4] 2> 561344 T2853 C733 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={slave=false&command=details&wt=javabin&qt=/replication&version=2} status=0 QTime=0
[junit4] 2> ASYNC NEW_CORE C734 name=collection1 org.apache.solr.core.SolrCore@2867e6fb
[junit4] 2> 561344 T2882 C734 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details&_trace=getDetails&wt=javabin&qt=/replication&version=2} status=0 QTime=3
[junit4] 2> 561365 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2076918884
[junit4] 2> 561366 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2867e6fb
[junit4] 2> 561366 T2844 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> 561366 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 561366 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 561367 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 561367 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 561368 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 561368 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index;done=false>>]
[junit4] 2> 561368 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data/index
[junit4] 2> 561368 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data;done=false>>]
[junit4] 2> 561369 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119692/repeater/collection1/data
[junit4] 2> 561369 T2844 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 561422 T2844 oas.SolrTestCaseJ4.tearDown ###Ending doTestDetails
[junit4] 2> 561443 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1292930659
[junit4] 2> 561444 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@67de7984
[junit4] 2> 561444 T2844 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=3,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 561445 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 561445 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 561445 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 561446 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 561446 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 561446 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index;done=false>>]
[junit4] 2> 561447 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data/index
[junit4] 2> 561447 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data;done=false>>]
[junit4] 2> 561447 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119396/master/collection1/data
[junit4] 2> 561447 T2844 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 561520 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=537622379
[junit4] 2> 561521 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@58c7cc5
[junit4] 2> 561521 T2844 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> 561521 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 561521 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 561522 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 561523 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 561523 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 561523 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data;done=false>>]
[junit4] 2> 561523 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data
[junit4] 2> 561524 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index;done=false>>]
[junit4] 2> 561524 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119474/slave/collection1/data/index
[junit4] 2> 561524 T2844 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 561579 T2844 oas.SolrTestCaseJ4.setUp ###Starting doTestBackup
[junit4] 2> 561582 T2844 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 561583 T2844 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57862
[junit4] 2> 561584 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 561584 T2844 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 561585 T2844 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master
[junit4] 2> 561585 T2844 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/'
[junit4] 2> 561593 T2844 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/solr.xml
[junit4] 2> 561600 T2844 oasc.CoreContainer.<init> New CoreContainer 450637877
[junit4] 2> 561600 T2844 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/]
[junit4] 2> 561601 T2844 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 561601 T2844 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 561601 T2844 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 561601 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 561601 T2844 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 561602 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 561602 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 561602 T2844 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 561602 T2844 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 561602 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 561603 T2844 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 561604 T2844 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 561605 T2898 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1
[junit4] 2> 561605 T2898 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/'
[junit4] 2> 561617 T2898 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 561630 T2898 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 561631 T2898 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 561632 T2898 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561635 T2898 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561635 T2898 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 561635 T2898 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/data/
[junit4] 2> 561635 T2898 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 561636 T2898 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/data
[junit4] 2> 561636 T2898 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/data/index/
[junit4] 2> 561636 T2898 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 561636 T2898 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764119993/master/collection1/data/index
[junit4] 2> 561636 T2898 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=85.9326171875, floorSegmentMB=0.5556640625, forceMergeDeletesPctAllowed=20.08281099448092, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.419057191051459
[junit4] 2> 561637 T2898 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@606fe092 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@370a4e76),segFN=segments_1,generation=1}
[junit4] 2> 561637 T2898 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561638 T2898 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 561638 T2898 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 561640 T2898 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 561640 T2898 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 561640 T2898 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 561641 T2898 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1261068733, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 561641 T2898 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@606fe092 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@370a4e76),segFN=segments_1,generation=1}
[junit4] 2> 561641 T2898 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561641 T2898 oass.SolrIndexSearcher.<init> Opening Searcher@55ca4486 main
[junit4] 2> 561642 T2898 oash.ReplicationHandler.inform Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 561642 T2898 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 561642 T2898 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 561642 T2899 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@55ca4486 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 561642 T2844 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 561643 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 561643 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 561646 T2844 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 561647 T2844 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45027
[junit4] 2> 561648 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 561648 T2844 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 561649 T2844 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave
[junit4] 2> 561649 T2844 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/'
[junit4] 2> 561655 T2844 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/solr.xml
[junit4] 2> 561662 T2844 oasc.CoreContainer.<init> New CoreContainer 698556612
[junit4] 2> 561662 T2844 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/]
[junit4] 2> 561663 T2844 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 561663 T2844 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 561663 T2844 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 561663 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 561663 T2844 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 561664 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 561664 T2844 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 561664 T2844 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 561664 T2844 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 561664 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 561665 T2844 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 561665 T2844 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 561666 T2910 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1
[junit4] 2> 561667 T2910 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/'
[junit4] 2> 561679 T2910 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 561685 T2910 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 561686 T2910 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 561688 T2910 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 561695 T2910 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 561696 T2910 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 561696 T2910 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/data/
[junit4] 2> 561696 T2910 oasc.SolrCore.<init> JMX monitoring not detected for core: collection1
[junit4] 2> 561696 T2910 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/data
[junit4] 2> 561696 T2910 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/data/index/
[junit4] 2> 561697 T2910 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/data/index' doesn't exist. Creating new index...
[junit4] 2> 561697 T2910 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764120058/slave/collection1/data/index
[junit4] 2> 561697 T2910 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=85.9326171875, floorSegmentMB=0.5556640625, forceMergeDeletesPctAllowed=20.08281099448092, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.419057191051459
[junit4] 2> 561697 T2910 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@21ac1b06 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b2bc6e4),segFN=segments_1,generation=1}
[junit4] 2> 561698 T2910 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561698 T2910 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 561698 T2910 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 561698 T2910 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4] 2> 561698 T2910 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4] 2> 561699 T2910 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4] 2> 561699 T2910 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 561699 T2910 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 561700 T2910 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 561700 T2910 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 561700 T2910 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 561701 T2910 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1261068733, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 561701 T2910 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@21ac1b06 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b2bc6e4),segFN=segments_1,generation=1}
[junit4] 2> 561701 T2910 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 561701 T2910 oass.SolrIndexSearcher.<init> Opening Searcher@4ac24b74 main
[junit4] 2> 561702 T2910 oash.SnapPuller.startExecutorService Poll Scheduled at an interval of 1000ms
[junit4] 2> 561702 T2911 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ac24b74 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 561702 T2910 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 561702 T2844 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 561703 T2844 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 561703 T2844 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 561724 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=450637877
[junit4] 2> 561725 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2abc52c3
[junit4] 2> 561725 T2844 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> 561725 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 561726 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 561726 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 561727 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 561727 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 561727 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/so
[...truncated too long message...]
icationHandler$SolrInstance-1380764179504/slave/collection1/data/index.20131002223620005;done=true>>]
[junit4] 2> 621621 T3531 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data/index.20131002223620005
[junit4] 2> 621653 T3527 C812 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={sort=id+desc&q=*:*&wt=javabin&version=2} hits=2 status=0 QTime=0
[junit4] 2> 621654 T2844 oas.SolrTestCaseJ4.tearDown ###Ending doTestReplicateAfterCoreReload
[junit4] 2> 621674 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1983355046
[junit4] 2> 621675 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@7e3872cc
[junit4] 2> 621675 T2844 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 621676 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 621676 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 621676 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 621677 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 621677 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 621677 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data;done=false>>]
[junit4] 2> 621678 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data
[junit4] 2> 621678 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data/index;done=false>>]
[junit4] 2> 621678 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179408/master/collection1/data/index
[junit4] 2> 621679 T2844 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 621751 T2844 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=642407844
[junit4] 2> 621751 T2844 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@785d2d23
[junit4] 2> 621752 T2844 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> 621752 T2844 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 621752 T2844 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 621753 T2844 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 621753 T2844 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 621753 T2844 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 621753 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data/index;done=false>>]
[junit4] 2> 621754 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data/index
[junit4] 2> 621754 T2844 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data;done=false>>]
[junit4] 2> 621754 T2844 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1380764179504/slave/collection1/data
[junit4] 2> 621755 T2844 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 621812 T2844 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene45: {newname=PostingsFormat(name=NestedPulsing), id=PostingsFormat(name=NestedPulsing), name=PostingsFormat(name=NestedPulsing)}, docValues:{}, sim=DefaultSimilarity, locale=es_BO, timezone=AGT
[junit4] 2> NOTE: Linux 3.8.0-31-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=157419048,total=377065472
[junit4] 2> NOTE: All tests run in this JVM: [TestCoreContainer, UpdateParamsTest, TestFieldResource, TestValueSourceCache, TestElisionMultitermQuery, TestSchemaNameResource, TestReversedWildcardFilterFactory, TestPerFieldSimilarity, UUIDFieldTest, DOMUtilTest, TestBadConfig, CoreAdminHandlerTest, MBeansHandlerTest, TestQueryUtils, BJQParserTest, TestJmxMonitoredMap, HdfsSyncSliceTest, StatelessScriptUpdateProcessorFactoryTest, CircularListTest, AnalysisAfterCoreReloadTest, LoggingHandlerTest, HdfsChaosMonkeySafeLeaderTest, TestMergePolicyConfig, TestLMJelinekMercerSimilarityFactory, TestSolrQueryParserDefaultOperatorResource, TestDocumentBuilder, DocValuesMissingTest, BasicFunctionalityTest, AddSchemaFieldsUpdateProcessorFactoryTest, URLClassifyProcessorTest, TestDocSet, TestUniqueKeyFieldResource, OverseerTest, TestSuggestSpellingConverter, SliceStateTest, QueryEqualityTest, ResponseLogComponentTest, TestSolrXml, TestPHPSerializedResponseWriter, SolrInfoMBeanTest, SampleTest, ClusterStateTest, ExternalFileFieldSortTest, TestSurroundQueryParser, LeaderElectionTest, TestCloudManagedSchemaAddField, TestSearchPerf, DistributedTermsComponentTest, FieldMutatingUpdateProcessorTest, TestSystemIdResolver, TestNoOpRegenerator, UnloadDistributedZkTest, TermsComponentTest, SyncSliceTest, DistributedSpellCheckComponentTest, EchoParamsTest, HdfsLockFactoryTest, SystemInfoHandlerTest, SolrIndexSplitterTest, TestLRUCache, ResourceLoaderTest, SolrCoreTest, HdfsUnloadDistributedZkTest, CachingDirectoryFactoryTest, SpellPossibilityIteratorTest, WordBreakSolrSpellCheckerTest, SimpleFacetsTest, HdfsCollectionsAPIDistributedZkTest, PolyFieldTest, JsonLoaderTest, TestCharFilters, TermVectorComponentTest, FastVectorHighlighterTest, BinaryUpdateRequestHandlerTest, CopyFieldTest, InfoHandlerTest, TestWriterPerf, TestPseudoReturnFields, MoreLikeThisHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, LeaderElectionIntegrationTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler]
[junit4] Completed on J0 in 60.85s, 14 tests, 1 failure <<< FAILURES!
[...truncated 473 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:427: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:407: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 327 suites, 1454 tests, 1 failure, 38 ignored (6 assumptions)
Total time: 37 minutes 18 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b106 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.6.0_45) - Build # 7621
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7621/
Java: 32bit/jdk1.6.0_45 -server -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_1 expected:<262> but was:<225>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_1 expected:<262> but was:<225>
at __randomizedtesting.SeedInfo.seed([C0972805AF7FB391:4171A61DD820D3AD]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:318)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:192)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 10099 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 1697798 T5367 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /wc_jit/yg
[junit4] 2> 1697802 T5367 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1380770828477
[junit4] 2> 1697803 T5367 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1697803 T5368 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1697903 T5367 oasc.ZkTestServer.run start zk server on port:40526
[junit4] 2> 1697905 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1697914 T5374 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d9faf8 name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1697915 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1697915 T5367 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1697920 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1697922 T5376 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bc91f name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1697922 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1697922 T5367 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1697926 T5367 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1697931 T5367 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1697935 T5367 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1697939 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1697940 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1697947 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1697947 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1697953 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1697953 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1697959 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1697959 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1697964 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1697965 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1697969 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1697970 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1697975 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1697975 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1697980 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1697980 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1697985 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1697986 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1697991 T5367 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1697991 T5367 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1698070 T5367 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1698072 T5367 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49773
[junit4] 2> 1698072 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1698073 T5367 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1698073 T5367 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671
[junit4] 2> 1698074 T5367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/'
[junit4] 2> 1698085 T5367 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/solr.xml
[junit4] 2> 1698127 T5367 oasc.CoreContainer.<init> New CoreContainer 23024916
[junit4] 2> 1698128 T5367 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/]
[junit4] 2> 1698129 T5367 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1698130 T5367 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1698130 T5367 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1698131 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1698131 T5367 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1698131 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1698132 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1698132 T5367 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1698133 T5367 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1698133 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1698134 T5367 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1698135 T5367 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1698135 T5367 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40526/solr
[junit4] 2> 1698136 T5367 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1698137 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1698138 T5387 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1cad459 name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698139 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1698140 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1698142 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1698143 T5389 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1002e78 name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1698143 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1698145 T5367 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1698149 T5367 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1698153 T5367 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1698156 T5367 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49773_wc_jit%2Fyg
[junit4] 2> 1698157 T5367 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49773_wc_jit%2Fyg
[junit4] 2> 1698161 T5367 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1698167 T5367 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1698171 T5367 oasc.Overseer.start Overseer (id=90490197015199747-127.0.0.1:49773_wc_jit%2Fyg-n_0000000000) starting
[junit4] 2> 1698175 T5367 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1698179 T5391 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1698181 T5367 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1698184 T5367 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1698187 T5367 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1698191 T5390 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1698194 T5392 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1698194 T5392 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1698195 T5392 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1699696 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1699697 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49773/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49773_wc_jit%2Fyg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1699697 T5390 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1699697 T5390 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1699702 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1700195 T5392 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1700196 T5392 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/collection1
[junit4] 2> 1700196 T5392 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1700197 T5392 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1700197 T5392 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1700199 T5392 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/collection1/'
[junit4] 2> 1700200 T5392 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/collection1/lib/classes/' to classloader
[junit4] 2> 1700200 T5392 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/collection1/lib/README' to classloader
[junit4] 2> 1700247 T5392 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1700296 T5392 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1700298 T5392 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1700308 T5392 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1700706 T5392 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1700720 T5392 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1700721 T5392 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1700725 T5392 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1700758 T5392 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1700758 T5392 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1380770828671/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1380770828477/control/data/
[junit4] 2> 1700759 T5392 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a9d95
[junit4] 2> 1700760 T5392 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/control/data
[junit4] 2> 1700760 T5392 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1380770828477/control/data/index/
[junit4] 2> 1700760 T5392 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1380770828477/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1700761 T5392 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/control/data/index
[junit4] 2> 1700761 T5392 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=70.259765625, floorSegmentMB=0.9716796875, forceMergeDeletesPctAllowed=24.514232616752548, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1700761 T5392 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@749645 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16a7f38),segFN=segments_1,generation=1}
[junit4] 2> 1700762 T5392 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1700764 T5392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1700765 T5392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1700765 T5392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1700765 T5392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1700765 T5392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1700766 T5392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1700766 T5392 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1700766 T5392 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1700767 T5392 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1700767 T5392 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1700767 T5392 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1700768 T5392 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1700768 T5392 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1700768 T5392 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1700769 T5392 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1700771 T5392 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1700773 T5392 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1700773 T5392 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1700774 T5392 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2928231229919083]
[junit4] 2> 1700774 T5392 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@749645 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16a7f38),segFN=segments_1,generation=1}
[junit4] 2> 1700775 T5392 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1700775 T5392 oass.SolrIndexSearcher.<init> Opening Searcher@16c24cc main
[junit4] 2> 1700777 T5393 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16c24cc main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1700779 T5392 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1700779 T5392 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49773/wc_jit/yg collection:control_collection shard:shard1
[junit4] 2> 1700779 T5392 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1700781 T5392 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1700790 T5392 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1700793 T5392 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1700793 T5392 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1700793 T5392 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49773/wc_jit/yg/collection1/
[junit4] 2> 1700794 T5392 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1700794 T5392 oasc.SyncStrategy.syncToMe http://127.0.0.1:49773/wc_jit/yg/collection1/ has no replicas
[junit4] 2> 1700794 T5392 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49773/wc_jit/yg/collection1/ shard1
[junit4] 2> 1700794 T5392 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1701208 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1701228 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1701253 T5392 oasc.ZkController.register We are http://127.0.0.1:49773/wc_jit/yg/collection1/ and leader is http://127.0.0.1:49773/wc_jit/yg/collection1/
[junit4] 2> 1701253 T5392 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49773/wc_jit/yg
[junit4] 2> 1701253 T5392 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1701253 T5392 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1701254 T5392 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1701256 T5392 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1701257 T5367 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1701258 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1701258 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1701259 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1701260 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1701261 T5396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c83cd6 name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1701262 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1701263 T5367 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1701266 T5367 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1701334 T5367 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1701336 T5367 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47228
[junit4] 2> 1701336 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1701337 T5367 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1701337 T5367 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941
[junit4] 2> 1701338 T5367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/'
[junit4] 2> 1701349 T5367 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/solr.xml
[junit4] 2> 1701402 T5367 oasc.CoreContainer.<init> New CoreContainer 31156224
[junit4] 2> 1701403 T5367 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/]
[junit4] 2> 1701404 T5367 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1701405 T5367 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1701405 T5367 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1701406 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1701406 T5367 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1701406 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1701407 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1701407 T5367 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1701408 T5367 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1701408 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1701409 T5367 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1701410 T5367 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1701410 T5367 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40526/solr
[junit4] 2> 1701411 T5367 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1701412 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1701413 T5407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@189136c name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1701413 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1701415 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1701416 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1701417 T5409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e8b7b2 name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1701418 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1701423 T5367 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1702427 T5367 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47228_wc_jit%2Fyg
[junit4] 2> 1702429 T5367 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47228_wc_jit%2Fyg
[junit4] 2> 1702432 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1702433 T5396 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1702434 T5409 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1702436 T5389 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1702445 T5410 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1702445 T5410 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1702447 T5410 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1702736 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1702737 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49773/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49773_wc_jit%2Fyg",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1702741 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:47228/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47228_wc_jit%2Fyg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1702742 T5390 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1702742 T5390 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1702746 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1702746 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1702746 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1703447 T5410 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1703448 T5410 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/collection1
[junit4] 2> 1703448 T5410 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1703449 T5410 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1703449 T5410 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1703451 T5410 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/collection1/'
[junit4] 2> 1703452 T5410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/collection1/lib/classes/' to classloader
[junit4] 2> 1703452 T5410 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/collection1/lib/README' to classloader
[junit4] 2> 1703495 T5410 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1703539 T5410 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1703541 T5410 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1703551 T5410 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1703957 T5410 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1703960 T5410 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1703962 T5410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1703966 T5410 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1704001 T5410 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1704002 T5410 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1380770831941/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty1/
[junit4] 2> 1704002 T5410 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a9d95
[junit4] 2> 1704003 T5410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty1
[junit4] 2> 1704004 T5410 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty1/index/
[junit4] 2> 1704004 T5410 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1704005 T5410 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty1/index
[junit4] 2> 1704005 T5410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=70.259765625, floorSegmentMB=0.9716796875, forceMergeDeletesPctAllowed=24.514232616752548, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1704006 T5410 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@e134ac lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@86f22b),segFN=segments_1,generation=1}
[junit4] 2> 1704006 T5410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1704011 T5410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1704011 T5410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1704012 T5410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1704012 T5410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1704012 T5410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1704013 T5410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1704013 T5410 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1704014 T5410 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1704014 T5410 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1704015 T5410 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1704016 T5410 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1704016 T5410 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1704017 T5410 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1704017 T5410 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1704018 T5410 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1704021 T5410 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1704025 T5410 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1704026 T5410 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1704027 T5410 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2928231229919083]
[junit4] 2> 1704027 T5410 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@e134ac lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@86f22b),segFN=segments_1,generation=1}
[junit4] 2> 1704028 T5410 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1704028 T5410 oass.SolrIndexSearcher.<init> Opening Searcher@6008ad main
[junit4] 2> 1704041 T5411 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6008ad main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1704044 T5410 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1704044 T5410 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47228/wc_jit/yg collection:collection1 shard:shard1
[junit4] 2> 1704044 T5410 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1704047 T5410 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1704060 T5410 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1704064 T5410 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1704065 T5410 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1704065 T5410 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47228/wc_jit/yg/collection1/
[junit4] 2> 1704065 T5410 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1704066 T5410 oasc.SyncStrategy.syncToMe http://127.0.0.1:47228/wc_jit/yg/collection1/ has no replicas
[junit4] 2> 1704066 T5410 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47228/wc_jit/yg/collection1/ shard1
[junit4] 2> 1704066 T5410 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1704256 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1704266 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1704266 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1704266 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1704276 T5410 oasc.ZkController.register We are http://127.0.0.1:47228/wc_jit/yg/collection1/ and leader is http://127.0.0.1:47228/wc_jit/yg/collection1/
[junit4] 2> 1704276 T5410 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47228/wc_jit/yg
[junit4] 2> 1704277 T5410 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1704277 T5410 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1704277 T5410 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1704279 T5410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1704280 T5367 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1704281 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1704281 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1704357 T5367 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1704358 T5367 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45752
[junit4] 2> 1704359 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1704359 T5367 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1704360 T5367 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956
[junit4] 2> 1704360 T5367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/'
[junit4] 2> 1704371 T5367 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/solr.xml
[junit4] 2> 1704414 T5367 oasc.CoreContainer.<init> New CoreContainer 4394401
[junit4] 2> 1704415 T5367 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/]
[junit4] 2> 1704416 T5367 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1704416 T5367 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1704417 T5367 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1704417 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1704417 T5367 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1704418 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1704418 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1704419 T5367 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1704419 T5367 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1704419 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1704421 T5367 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1704421 T5367 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1704421 T5367 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40526/solr
[junit4] 2> 1704422 T5367 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1704423 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1704425 T5423 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33f560 name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1704425 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1704427 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1704429 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1704430 T5425 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a0bd2d name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1704430 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1704435 T5367 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1705440 T5367 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45752_wc_jit%2Fyg
[junit4] 2> 1705442 T5367 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45752_wc_jit%2Fyg
[junit4] 2> 1705444 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1705445 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1705448 T5409 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1705449 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1705450 T5396 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1705450 T5425 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1705451 T5389 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1705459 T5426 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1705459 T5426 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1705460 T5426 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1705778 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1705779 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47228/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:47228_wc_jit%2Fyg",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1705785 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45752/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45752_wc_jit%2Fyg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1705785 T5390 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1705785 T5390 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1705790 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1705790 T5425 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1705791 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1705791 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1706461 T5426 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1706461 T5426 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/collection1
[junit4] 2> 1706461 T5426 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1706462 T5426 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1706462 T5426 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1706464 T5426 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/collection1/'
[junit4] 2> 1706464 T5426 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/collection1/lib/classes/' to classloader
[junit4] 2> 1706465 T5426 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/collection1/lib/README' to classloader
[junit4] 2> 1706516 T5426 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1706571 T5426 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1706573 T5426 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1706582 T5426 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1707018 T5426 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1707021 T5426 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1707022 T5426 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1707029 T5426 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1707072 T5426 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1707072 T5426 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty2-1380770834956/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty2/
[junit4] 2> 1707073 T5426 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a9d95
[junit4] 2> 1707074 T5426 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty2
[junit4] 2> 1707074 T5426 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty2/index/
[junit4] 2> 1707074 T5426 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1707076 T5426 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty2/index
[junit4] 2> 1707077 T5426 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=70.259765625, floorSegmentMB=0.9716796875, forceMergeDeletesPctAllowed=24.514232616752548, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1707078 T5426 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b55c8f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b46f2),segFN=segments_1,generation=1}
[junit4] 2> 1707078 T5426 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1707083 T5426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1707083 T5426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1707084 T5426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1707084 T5426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1707085 T5426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1707085 T5426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1707086 T5426 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1707086 T5426 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1707086 T5426 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1707087 T5426 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1707088 T5426 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1707088 T5426 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1707089 T5426 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1707089 T5426 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1707090 T5426 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1707093 T5426 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1707096 T5426 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1707097 T5426 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1707098 T5426 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2928231229919083]
[junit4] 2> 1707098 T5426 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@1b55c8f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b46f2),segFN=segments_1,generation=1}
[junit4] 2> 1707099 T5426 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1707099 T5426 oass.SolrIndexSearcher.<init> Opening Searcher@18f0f0c main
[junit4] 2> 1707103 T5427 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18f0f0c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1707106 T5426 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1707106 T5426 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45752/wc_jit/yg collection:collection1 shard:shard2
[junit4] 2> 1707106 T5426 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1707108 T5426 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1707118 T5426 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1707121 T5426 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1707121 T5426 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1707122 T5426 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45752/wc_jit/yg/collection1/
[junit4] 2> 1707122 T5426 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1707122 T5426 oasc.SyncStrategy.syncToMe http://127.0.0.1:45752/wc_jit/yg/collection1/ has no replicas
[junit4] 2> 1707123 T5426 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45752/wc_jit/yg/collection1/ shard2
[junit4] 2> 1707123 T5426 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1707303 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1707313 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1707313 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1707314 T5425 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1707314 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1707332 T5426 oasc.ZkController.register We are http://127.0.0.1:45752/wc_jit/yg/collection1/ and leader is http://127.0.0.1:45752/wc_jit/yg/collection1/
[junit4] 2> 1707333 T5426 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45752/wc_jit/yg
[junit4] 2> 1707333 T5426 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1707333 T5426 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1707334 T5426 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1707336 T5426 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1707337 T5367 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1707338 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1707338 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1707411 T5367 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1707413 T5367 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:38252
[junit4] 2> 1707414 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1707414 T5367 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1707415 T5367 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013
[junit4] 2> 1707415 T5367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/'
[junit4] 2> 1707426 T5367 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/solr.xml
[junit4] 2> 1707461 T5367 oasc.CoreContainer.<init> New CoreContainer 7449222
[junit4] 2> 1707461 T5367 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/]
[junit4] 2> 1707468 T5367 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1707469 T5367 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1707469 T5367 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1707470 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1707470 T5367 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1707470 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1707471 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1707471 T5367 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1707472 T5367 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1707472 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1707473 T5367 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1707474 T5367 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1707474 T5367 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40526/solr
[junit4] 2> 1707475 T5367 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1707475 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1707477 T5439 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d19f12 name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1707477 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1707479 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1707480 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1707482 T5441 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8f39fb name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1707482 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1707487 T5367 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1708491 T5367 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38252_wc_jit%2Fyg
[junit4] 2> 1708493 T5367 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38252_wc_jit%2Fyg
[junit4] 2> 1708496 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1708496 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 1708499 T5425 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1708499 T5425 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708500 T5441 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1708501 T5409 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1708502 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708504 T5389 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1708506 T5396 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1708513 T5442 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1708514 T5442 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1708515 T5442 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1708826 T5390 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1708827 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:45752/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45752_wc_jit%2Fyg",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1708831 T5390 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:38252/wc_jit/yg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:38252_wc_jit%2Fyg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 1708832 T5390 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1708832 T5390 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1708837 T5425 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708838 T5389 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708838 T5441 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708838 T5409 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1708837 T5396 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 1709515 T5442 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1709516 T5442 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/collection1
[junit4] 2> 1709516 T5442 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1709517 T5442 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1709517 T5442 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1709519 T5442 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/collection1/'
[junit4] 2> 1709520 T5442 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/collection1/lib/classes/' to classloader
[junit4] 2> 1709520 T5442 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/collection1/lib/README' to classloader
[junit4] 2> 1709564 T5442 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 1709611 T5442 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1709613 T5442 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1709622 T5442 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1710005 T5442 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1710007 T5442 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1710009 T5442 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1710014 T5442 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1710062 T5442 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1710063 T5442 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1380770838013/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty3/
[junit4] 2> 1710063 T5442 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3a9d95
[junit4] 2> 1710064 T5442 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty3
[junit4] 2> 1710064 T5442 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty3/index/
[junit4] 2> 1710065 T5442 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1710065 T5442 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1380770828477/jetty3/index
[junit4] 2> 1710066 T5442 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=70.259765625, floorSegmentMB=0.9716796875, forceMergeDeletesPctAllowed=24.514232616752548, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1710066 T5442 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7a6769 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f026f),segFN=segments_1,generation=1}
[junit4] 2> 1710067 T5442 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1710070 T5442 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1710070 T5442 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1710070 T5442 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1710071 T5442 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1710071 T5442 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1710071 T5442 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1710072 T5442 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1710072 T5442 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1710072 T5442 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1710073 T5442 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1710073 T5442 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1710074 T5442 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1710074 T5442 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1710075 T5442 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1710075 T5442 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1710078 T5442 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1710082 T5442 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1710082 T5442 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1710083 T5442 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=10, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2928231229919083]
[junit4] 2> 1710083 T5442 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7a6769 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f026f),segFN=segments_1,generation=1}
[junit4] 2> 1710083 T5442 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1710084 T5442 oass.SolrIndexSearcher.<init> Opening Searcher@1076dda main
[junit4] 2> 1710087 T5443 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1076dda main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1710089 T5442 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1710089 T5442 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38252/wc_jit/yg collection:collection1 shard:shard1
[junit4] 2> 1710089 T5442 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1710093 T5442 oasc.ZkController.register We are http://127.0.0.1:38252/wc_jit/yg/collection1/ and leader is http://127.0.0.1:47228/wc_jit/yg/collection1/
[junit4] 2> 1710094 T5442 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38252/wc_jit/yg
[junit4] 2> 1710094 T5442 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1710094 T5442 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C22065 name=collection1 org.apache.solr.core.SolrCore@1303d83 url=http://127.0.0.1:38252/wc_jit/yg/collection1 node=127.0.0.1:38252_wc_jit%2Fyg C22065_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:38252/wc_jit/yg, core=collection1, node_name=127.0.0.1:38252_wc_jit%2Fyg}
[junit4] 2> 1710095 T5444 C22065 P38252 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1710095 T5442 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1710096 T5444 C22065 P38252 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1710096 T5444 C22065 P38252 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1710097 T5444 C22065 P38252 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1710097 T5367 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 1710098 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1710098 T5444 C22065 P38252 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1710099 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1710100 T5402 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1710177 T5367 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1710179 T5367 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47913
[junit4] 2> 1710180 T5367 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1710180 T5367 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1710181 T5367 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1380770840774
[junit4] 2> 1710181 T5367 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1380770840774/'
[junit4] 2> 1710193 T5367 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1380770840774/solr.xml
[junit4] 2> 1710246 T5367 oasc.CoreContainer.<init> New CoreContainer 20247325
[junit4] 2> 1710247 T5367 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1380770840774/]
[junit4] 2> 1710248 T5367 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1710249 T5367 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1710249 T5367 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1710249 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1710250 T5367 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1710250 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1710251 T5367 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1710251 T5367 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1710251 T5367 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1710252 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1710253 T5367 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1710254 T5367 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1710254 T5367 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40526/solr
[junit4] 2> 1710255 T5367 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1710255 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1710257 T5456 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1451970 name:ZooKeeperConnection Watcher:127.0.0.1:40526 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1710257 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1710259 T5367 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1710261 T5367 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1710262 T5458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dc0bfa name:ZooKeeperConnection Watcher:127.0.0.1:40526/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1710262 T5367 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeep
[...truncated too long message...]
oud.ShardSplitTest-1380770828477 FAILED !!!!!
[junit4] 2> 1875102 T5367 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1875102 T5367 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:40526 40526
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90490197015199747-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49773_wc_jit%2Fyg",
[junit4] 1> "base_url":"http://127.0.0.1:49773/wc_jit/yg"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90490197015199747-127.0.0.1:49773_wc_jit%2Fyg-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90490197015199752-127.0.0.1:45752_wc_jit%2Fyg-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90490197015199756-127.0.0.1:47913_wc_jit%2Fyg-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90490197015199754-127.0.0.1:38252_wc_jit%2Fyg-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90490197015199750-127.0.0.1:47228_wc_jit%2Fyg-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90490197015199747-127.0.0.1:49773_wc_jit%2Fyg-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=C0972805AF7FB391 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=en_US -Dtests.timezone=Asia/Ulan_Bator -Dtests.file.encoding=UTF-8
[junit4] FAILURE 177s J0 | ShardSplitTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<262> but was:<225>
[junit4] > at __randomizedtesting.SeedInfo.seed([C0972805AF7FB391:4171A61DD820D3AD]:0)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:318)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:192)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 1875111 T5367 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 177316 T5366 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1876017 T5458 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1876017 T5458 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1876018 T5458 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45: {id=MockFixedIntBlock(blockSize=1144), _version_=MockVariableIntBlock(baseBlockSize=17), n_ti=MockVariableIntBlock(baseBlockSize=17)}, docValues:{}, sim=DefaultSimilarity, locale=en_US, timezone=Asia/Ulan_Bator
[junit4] 2> NOTE: Linux 3.8.0-31-generic i386/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=8,threads=3,free=63627184,total=256794624
[junit4] 2> NOTE: All tests run in this JVM: [ScriptEngineTest, TestSuggestSpellingConverter, PolyFieldTest, TestSolrXml, SynonymTokenizerTest, TestFaceting, TestSolrXMLSerializer, TestCloudManagedSchemaAddField, SpellPossibilityIteratorTest, ZkCLITest, UpdateRequestProcessorFactoryTest, TestLuceneMatchVersion, ZkControllerTest, TestExtendedDismaxParser, HdfsSyncSliceTest, CSVRequestHandlerTest, TermVectorComponentTest, DateMathParserTest, TestSolrQueryParser, TestGroupingSearch, TestNRTOpen, ShardRoutingTest, TestUniqueKeyFieldResource, TestSchemaResource, TestSolrIndexConfig, SearchHandlerTest, TestSchemaSimilarityResource, HdfsLockFactoryTest, TestReplicationHandler, FastVectorHighlighterTest, SolrCoreTest, SolrInfoMBeanTest, RegexBoostProcessorTest, TestRandomDVFaceting, ClusterStateUpdateTest, LegacyHTMLStripCharFilterTest, TestPseudoReturnFields, TestSystemIdResolver, TestValueSourceCache, TestReversedWildcardFilterFactory, TestSurroundQueryParser, TestPostingsSolrHighlighter, LoggingHandlerTest, TestConfig, TestRemoteStreaming, RecoveryZkTest, ExternalFileFieldSortTest, DirectUpdateHandlerOptimizeTest, TestNoOpRegenerator, TestPerFieldSimilarity, SampleTest, OverseerTest, TestLMJelinekMercerSimilarityFactory, TestSchemaNameResource, PeerSyncTest, ClusterStateTest, TestTrie, TestLRUCache, TestSearchPerf, SuggesterFSTTest, DistributedSpellCheckComponentTest, ResponseLogComponentTest, DistributedTermsComponentTest, TestShardHandlerFactory, BJQParserTest, AutoCommitTest, HdfsDirectoryTest, MoreLikeThisHandlerTest, TestAnalyzeInfixSuggestions, TestSort, BasicDistributedZkTest, PrimitiveFieldTypeTest, AddSchemaFieldsUpdateProcessorFactoryTest, HdfsCollectionsAPIDistributedZkTest, DocValuesMissingTest, URLClassifyProcessorTest, CachingDirectoryFactoryTest, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, BasicZkTest, TestRandomFaceting, LeaderElectionTest, ZkSolrClientTest, SliceStateUpdateTest, TestDistributedGrouping, TestRecovery, TermVectorComponentDistributedTest, TestRealTimeGet, TestJoin, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, TestRangeQuery, TestCoreContainer, SimpleFacetsTest, TestSolr4Spatial, StatsComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, ConvertedLegacyTest, TestFunctionQuery, BasicFunctionalityTest, TestLazyCores, TestBadConfig, OverseerCollectionProcessorTest, TestIndexSearcher, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, TestCoreDiscovery, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, CoreAdminHandlerTest, SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTest, SpatialFilterTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, TestUpdate, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, QueryEqualityTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrDeletionPolicy1, DebugComponentTest, CacheHeaderTest, LukeRequestHandlerTest, TestQueryUtils, TestWriterPerf, DirectSolrSpellCheckerTest, FileBasedSpellCheckerTest, TermsComponentTest, RequestHandlersTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, RequiredFieldsTest, IndexSchemaTest, TestJmxIntegration, ReturnFieldsTest, MBeansHandlerTest, QueryParsingTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, BinaryUpdateRequestHandlerTest, TestPHPSerializedResponseWriter, PingRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestLFUCache, HighlighterConfigTest, SOLR749Test, UpdateParamsTest, AlternateDirectoryTest, CopyFieldTest, SolrIndexConfigTest, BadComponentTest, TestStressRecovery, TestMergePolicyConfig, TestSolrDeletionPolicy2, TestDocSet, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, NotRequiredUniqueKeyTest, TestCharFilters, EchoParamsTest, TestSweetSpotSimilarityFactory, TestNumberUtils, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestJmxMonitoredMap, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, TestFastLRUCache, PreAnalyzedFieldTest, DateFieldTest, DOMUtilTest, RAMDirectoryFactoryTest, TestSolrJ, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, CircularListTest, TestRTGBase, SolrTestCaseJ4Test, TestCollationKeyRangeQueries, AssignTest, ShardSplitTest]
[junit4] Completed on J0 in 178.35s, 1 test, 1 failure <<< FAILURES!
[...truncated 31 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:427: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:407: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:451: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1233: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:876: There were test failures: 327 suites, 1454 tests, 1 failure, 35 ignored (7 assumptions)
Total time: 53 minutes 46 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure