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 2017/02/09 07:11:41 UTC
[JENKINS] Lucene-Solr-5.5-Windows (32bit/jdk1.7.0_80) - Build # 133
- Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-5.5-Windows/133/
Java: 32bit/jdk1.7.0_80 -client -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
[C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\index.20170209010626201, C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\index.20170209010626547, C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\] expected:<2> but was:<3>
Stack Trace:
java.lang.AssertionError: [C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\index.20170209010626201, C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\index.20170209010626547, C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-012\.\collection1\data\] expected:<2> but was:<3>
at __randomizedtesting.SeedInfo.seed([1D55CD45350242B3:EA26231DF3EAED55]: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.handler.TestReplicationHandler.checkForSingleIndex(TestReplicationHandler.java:898)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1328)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11297 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\init-core-data-001
[junit4] 2> 1688739 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyCommits
[junit4] 2> 1688740 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1
[junit4] 2> 1688758 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 1688760 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@17c469d{/solr,null,AVAILABLE}
[junit4] 2> 1688762 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.ServerConnector Started ServerConnector@1ffef34{HTTP/1.1}{127.0.0.1:57647}
[junit4] 2> 1688762 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.Server Started @1694610ms
[junit4] 2> 1688762 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostPort=57647, solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1\data, hostContext=/solr}
[junit4] 2> 1688763 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@a5c9f1
[junit4] 2> 1688763 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001'
[junit4] 2> 1688763 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1688763 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1688764 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\solr.xml
[junit4] 2> 1688834 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.
[junit4] 2> 1688835 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer New CoreContainer 20247563
[junit4] 2> 1688835 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001]
[junit4] 2> 1688835 WARN (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Couldn't add files from C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\lib to classpath: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\lib
[junit4] 2> 1688836 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,connectionsEvictorSleepDelay : 5000,maxConnectionIdleTime : 40000,
[junit4] 2> 1688843 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1688844 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1688844 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1688844 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 1688844 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 1688846 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.
[junit4] 2> 1688851 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {loadOnStartup=true, config=solrconfig.xml, dataDir=data\, name=collection1, transient=false, configSetProperties=configsetprops.json, schema=schema.xml}
[junit4] 2> 1688851 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Found core collection1 in C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1
[junit4] 2> 1688852 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 1688852 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter user.dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0
[junit4] 2> 1688852 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 1688853 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1'
[junit4] 2> 1688853 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1688853 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1688892 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 1688937 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.4
[junit4] 2> 1688979 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1688986 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1689001 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 1689017 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1'
[junit4] 2> 1689017 INFO (coreLoadExecutor-4158-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1
[junit4] 2> 1689018 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1689018 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\]
[junit4] 2> 1689018 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore JMX monitoring not detected for core: collection1
[junit4] 2> 1689019 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\
[junit4] 2> 1689019 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\index/
[junit4] 2> 1689019 WARN (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 1689019 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\index
[junit4] 2> 1689019 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=64.9033203125, floorSegmentMB=1.427734375, forceMergeDeletesPctAllowed=19.619474828315244, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2949980191489102
[junit4] 2> 1689020 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_1,generation=1}
[junit4] 2> 1689020 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689020 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [ x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\.\collection1\data\
[junit4] 2> 1689023 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1689033 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689036 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689038 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689040 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689042 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 1689042 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/properties,/update,/replication,/admin/luke,/schema,/admin/plugins,/admin/ping,/config,defaults,/admin/logging,/update/json/docs,/admin/file,/admin/mbeans,/admin/segments,/admin/threads,lazy,/get,/admin/system,standard,/update/csv,/update/json
[junit4] 2> 1689044 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 1689044 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1689044 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1689045 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=39.6435546875, floorSegmentMB=2.0751953125, forceMergeDeletesPctAllowed=5.544275054310161, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1689045 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_1,generation=1}
[junit4] 2> 1689045 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689045 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@fa8933[collection1] main
[junit4] 2> 1689047 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1\conf
[junit4] 2> 1689047 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageDir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1\conf}
[junit4] 2> 1689047 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using file:dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-001\collection1\conf
[junit4] 2> 1689048 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1689048 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 1689048 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 1689048 INFO (searcherExecutor-4159-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@fa8933[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1689048 INFO (coreLoadExecutor-4158-thread-1) [ x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 1689356 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1
[junit4] 2> 1689371 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.Server jetty-9.2.13.v20150730
[junit4] 2> 1689372 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7e6137{/solr,null,AVAILABLE}
[junit4] 2> 1689374 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.ServerConnector Started ServerConnector@120956c{HTTP/1.1}{127.0.0.1:57651}
[junit4] 2> 1689374 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.e.j.s.Server Started @1695222ms
[junit4] 2> 1689374 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostPort=57651, hostContext=/solr, solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1\data}
[junit4] 2> 1689375 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@a5c9f1
[junit4] 2> 1689375 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002'
[junit4] 2> 1689375 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1689375 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1689377 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\solr.xml
[junit4] 2> 1689431 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Config-defined core root directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.
[junit4] 2> 1689431 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer New CoreContainer 24110408
[junit4] 2> 1689431 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002]
[junit4] 2> 1689432 WARN (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Couldn't add files from C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\lib to classpath: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\lib
[junit4] 2> 1689432 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 90000,urlScheme : ,connTimeout : 15000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,connectionsEvictorSleepDelay : 5000,maxConnectionIdleTime : 40000,
[junit4] 2> 1689437 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 1689439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1689439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1689439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 1689439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 1689441 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Looking for core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.
[junit4] 2> 1689447 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, transient=false, loadOnStartup=true, configSetProperties=configsetprops.json, schema=schema.xml, dataDir=data\, config=solrconfig.xml}
[junit4] 2> 1689447 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Found core collection1 in C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1
[junit4] 2> 1689448 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions
[junit4] 2> 1689449 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1'
[junit4] 2> 1689449 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter user.dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0
[junit4] 2> 1689449 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
[junit4] 2> 1689449 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1689449 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrResourceLoader solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 1689478 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 1689505 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.4
[junit4] 2> 1689559 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1689566 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 1689582 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 1689592 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1'
[junit4] 2> 1689592 INFO (coreLoadExecutor-4168-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1
[junit4] 2> 1689592 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1689593 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\]
[junit4] 2> 1689593 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore JMX monitoring not detected for core: collection1
[junit4] 2> 1689593 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\
[junit4] 2> 1689593 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index/
[junit4] 2> 1689593 WARN (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory 'C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index' doesn't exist. Creating new index...
[junit4] 2> 1689594 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index
[junit4] 2> 1689594 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=64.9033203125, floorSegmentMB=1.427734375, forceMergeDeletesPctAllowed=19.619474828315244, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2949980191489102
[junit4] 2> 1689594 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_1,generation=1}
[junit4] 2> 1689596 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689596 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [ x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\
[junit4] 2> 1689598 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1689608 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689610 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689610 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689615 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 1689617 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 1689617 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/properties,/update,/replication,/admin/luke,/schema,/admin/plugins,/admin/ping,/config,defaults,/admin/logging,/update/json/docs,/admin/file,/admin/mbeans,/admin/segments,/admin/threads,lazy,/get,/admin/system,standard,/update/csv,/update/json
[junit4] 2> 1689619 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=19, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=39.6435546875, floorSegmentMB=2.0751953125, forceMergeDeletesPctAllowed=5.544275054310161, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_1,generation=1}
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689620 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@1f76d94[collection1] main
[junit4] 2> 1689621 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1\conf
[junit4] 2> 1689621 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageDir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1\conf}
[junit4] 2> 1689621 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using file:dir=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\collection1\conf
[junit4] 2> 1689622 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 1689629 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 1689629 INFO (searcherExecutor-4169-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1f76d94[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 1689629 INFO (coreLoadExecutor-4168-thread-1) [ x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 1689632 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1689952 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&version=2&wt=javabin&sort=id+desc} hits=0 status=0 QTime=0
[junit4] 2> 1689955 INFO (qtp23810310-9194) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={version=2&wt=javabin}{add=[1]} 0 0
[junit4] 2> 1689956 INFO (qtp23810310-9195) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1689957 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_2,generation=2}
[junit4] 2> 1689957 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 1689958 INFO (qtp23810310-9195) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@483d8f[collection1] main
[junit4] 2> 1689959 INFO (qtp23810310-9195) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1689959 INFO (searcherExecutor-4159-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@483d8f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.4):C1)))}
[junit4] 2> 1689959 INFO (qtp23810310-9195) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin}{commit=} 0 3
[junit4] 2> 1689963 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1689967 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1689968 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 1689968 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 1689968 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1689981 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&version=2&command=filelist&wt=javabin&qt=/replication} status=0 QTime=11
[junit4] 2> 1689982 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10
[junit4] 2> 1689983 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554547
[junit4] 2> 1689984 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1689984 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=77.419921875, floorSegmentMB=1.42578125, forceMergeDeletesPctAllowed=19.471194675782037, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3134621717614252
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_1,generation=1}
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_1,generation=1}
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1689985 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@11a687c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c1e50e)
[junit4] 2> 1689986 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.nvd} status=0 QTime=0
[junit4] 2> 1689988 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.si} status=0 QTime=0
[junit4] 2> 1689990 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.nvm} status=0 QTime=0
[junit4] 2> 1689992 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.tim} status=0 QTime=0
[junit4] 2> 1689994 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.fdt} status=0 QTime=0
[junit4] 2> 1689996 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.fdx} status=0 QTime=0
[junit4] 2> 1689998 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.doc} status=0 QTime=0
[junit4] 2> 1689999 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.tip} status=0 QTime=0
[junit4] 2> 1690000 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_0.fnm} status=0 QTime=0
[junit4] 2> 1690001 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=segments_2} status=0 QTime=0
[junit4] 2> 1690001 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1396) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@11a687c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c1e50e)
[junit4] 2> 1690004 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1690005 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> 1690005 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 1690005 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1690007 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@b19b3b[collection1] main
[junit4] 2> 1690007 INFO (searcherExecutor-4169-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@b19b3b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.4):C1)))}
[junit4] 2> 1690007 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554547 [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554547;done=true>>]
[junit4] 2> 1690007 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554547
[junit4] 2> 1690007 INFO (qtp7035745-9212) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:57647/solr/collection1/replication} status=0 QTime=44
[junit4] 2> 1690010 INFO (qtp7035745-9213) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty1&version=2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=0
[junit4] 2> 1690010 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 1690012 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690014 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690019 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=details&wt=javabin&qt=/replication&slave=false} status=0 QTime=0
[junit4] 2> 1690019 INFO (qtp7035745-9214) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=3
[junit4] 2> 1690021 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690023 INFO (qtp7035745-9215) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690025 INFO (qtp23810310-9194) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1690026 INFO (qtp23810310-9194) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 1690026 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.SolrCore SolrIndexSearcher has not changed - not re-opening: org.apache.solr.search.SolrIndexSearcher
[junit4] 2> 1690026 INFO (qtp23810310-9194) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1690027 INFO (qtp23810310-9194) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin}{commit=} 0 1
[junit4] 2> 1690029 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1690032 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690033 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master.
[junit4] 2> 1690033 INFO (qtp7035745-9217) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:57647/solr/collection1/replication} status=0 QTime=4
[junit4] 2> 1690035 INFO (qtp23810310-9196) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={version=2&wt=javabin}{add=[2]} 0 1
[junit4] 2> 1690037 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1690040 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=3
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_3,generation=3}
[junit4] 2> 1690040 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1690041 INFO (qtp23810310-9197) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@262128[collection1] main
[junit4] 2> 1690041 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1690041 INFO (searcherExecutor-4159-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@262128[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.4):C1) Uninverting(_1(5.5.4):C1)))}
[junit4] 2> 1690042 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin}{commit=} 0 3
[junit4] 2> 1690045 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1690063 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690064 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 3
[junit4] 2> 1690064 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 1690064 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1690070 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&version=2&command=filelist&wt=javabin&qt=/replication} status=0 QTime=2
[junit4] 2> 1690070 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 19
[junit4] 2> 1690071 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554635
[junit4] 2> 1690072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1690072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=77.419921875, floorSegmentMB=1.42578125, forceMergeDeletesPctAllowed=19.471194675782037, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3134621717614252
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1f6266d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@154bf1c)
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 1690073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.tim because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.doc because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.tip because it already exists
[junit4] 2> 1690075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists
[junit4] 2> 1690077 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.fdx} status=0 QTime=0
[junit4] 2> 1690082 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.tip} status=0 QTime=0
[junit4] 2> 1690084 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.nvm} status=0 QTime=0
[junit4] 2> 1690086 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.tim} status=0 QTime=0
[junit4] 2> 1690088 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.fnm} status=0 QTime=0
[junit4] 2> 1690092 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.si} status=0 QTime=0
[junit4] 2> 1690093 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.doc} status=0 QTime=0
[junit4] 2> 1690097 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.nvd} status=0 QTime=0
[junit4] 2> 1690099 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_1.fdt} status=0 QTime=0
[junit4] 2> 1690101 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=segments_3} status=0 QTime=0
[junit4] 2> 1690102 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1462) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@1f6266d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@154bf1c)
[junit4] 2> 1690106 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=41, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 1690107 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1690107 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1690107 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1690108 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@1f94cbf[collection1] main
[junit4] 2> 1690108 INFO (searcherExecutor-4169-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1f94cbf[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.4):C1) Uninverting(_1(5.5.4):C1)))}
[junit4] 2> 1690109 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554635 [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554635;done=true>>]
[junit4] 2> 1690109 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554635
[junit4] 2> 1690109 INFO (qtp7035745-9216) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={command=fetchindex&wait=true&masterUrl=http://127.0.0.1:57647/solr/collection1/replication} status=0 QTime=65
[junit4] 2> 1690112 INFO (qtp7035745-9212) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty2&version=2&wt=javabin&sort=id+desc} hits=1 status=0 QTime=0
[junit4] 2> 1690112 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[1D55CD45350242B3]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 1690115 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690116 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690121 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=details&wt=javabin&qt=/replication&slave=false} status=0 QTime=0
[junit4] 2> 1690122 INFO (qtp7035745-9213) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&version=2&command=details&wt=javabin&qt=/replication} status=0 QTime=2
[junit4] 2> 1690123 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690127 INFO (qtp7035745-9214) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=1
[junit4] 2> 1690131 INFO (qtp23810310-9196) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={version=2&wt=javabin}{add=[3]} 0 0
[junit4] 2> 1690133 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 1690135 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=4
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@8c7324 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@db5027),segFN=segments_4,generation=4}
[junit4] 2> 1690136 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 4
[junit4] 2> 1690136 INFO (qtp23810310-9197) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@167f053[collection1] realtime
[junit4] 2> 1690136 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 1690136 INFO (qtp23810310-9197) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&version=2&wt=javabin&openSearcher=false}{commit=} 0 3
[junit4] 2> 1690139 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 1690143 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={version=2&command=indexversion&wt=javabin&qt=/replication} status=0 QTime=0
[junit4] 2> 1690144 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 4
[junit4] 2> 1690144 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 3
[junit4] 2> 1690144 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 1690147 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&version=2&command=filelist&wt=javabin&qt=/replication} status=0 QTime=1
[junit4] 2> 1690148 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 28
[junit4] 2> 1690148 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-002\.\collection1\data\index.20170209010554713
[junit4] 2> 1690149 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1690150 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=27, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=77.419921875, floorSegmentMB=1.42578125, forceMergeDeletesPctAllowed=19.471194675782037, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3134621717614252
[junit4] 2> 1690151 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1690152 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1690152 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 1690152 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1690152 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1690152 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1690153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1690153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1690153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1691153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1691153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1691153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1691153 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1692154 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1692155 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1692155 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1692155 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1693159 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1693159 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1693159 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1693159 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1694160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1694160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1694160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1694160 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1695161 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1695161 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1695161 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1695161 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1696162 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1696163 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1696163 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1696163 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1697164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1697164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1697164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1697164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1698164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1698164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1698164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1698164 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1699165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1699165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1699165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1699165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1700165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 1700165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@d8c5f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ac1387),segFN=segments_3,generation=3}
[junit4] 2> 1700165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 1700165 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 1701166 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher IndexFetcher slept for 11000ms for unused lucene index files to be delete-able
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@de1970 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1580a8f)
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.tim because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.doc because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.tip because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists
[junit4] 2> 1701167 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.tip because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.tim because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.doc because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists
[junit4] 2> 1701168 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists
[junit4] 2> 1701169 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.fnm} status=0 QTime=0
[junit4] 2> 1701172 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.nvd} status=0 QTime=0
[junit4] 2> 1701175 INFO (qtp23810310-9196) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.tip} status=0 QTime=0
[junit4] 2> 1701176 INFO (qtp23810310-9197) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.si} status=0 QTime=0
[junit4] 2> 1701179 INFO (qtp23810310-9192) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.fdx} status=0 QTime=0
[junit4] 2> 1701181 INFO (qtp23810310-9193) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.tim} status=0 QTime=0
[junit4] 2> 1701183 INFO (qtp23810310-9194) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&command=filecontent&wt=filestream&qt=/replication&checksum=true&file=_2.doc} status=0 QTime=0
[junit4] 2> 1701184 INFO (qtp23810310-9195) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={genera
[...truncated too long message...]
or-4883-thread-1) [ x:collection1] o.a.s.u.SolrCoreState Closing SolrCoreState
[junit4] 2> 1779037 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1779037 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState closing IndexWriter with IndexWriterCloser
[junit4] 2> 1779038 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
[junit4] 2> 1779038 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1779038 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\index.20170209010723494 [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\index.20170209010723494;done=false>>]
[junit4] 2> 1779038 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\index.20170209010723494
[junit4] 2> 1779038 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\;done=false>>]
[junit4] 2> 1779039 INFO (coreCloseExecutor-4883-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-033\.\collection1\data\
[junit4] 2> 1779039 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[1D55CD45350242B3]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@c10561{/solr,null,UNAVAILABLE}
[junit4] 2> 1779041 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[1D55CD45350242B3]) [ ] o.e.j.s.ServerConnector Stopped ServerConnector@f4cd85{HTTP/1.1}{127.0.0.1:0}
[junit4] 2> 1779041 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[1D55CD45350242B3]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=10504324
[junit4] 2> 1779042 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@a9391a
[junit4] 2> 1779042 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 closing DirectUpdateHandler2{commits=2,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=1,cumulative_errors=0}
[junit4] 2> 1779042 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.u.SolrCoreState Closing SolrCoreState
[junit4] 2> 1779042 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 1779042 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState closing IndexWriter with IndexWriterCloser
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\index.20170209010723297 [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\index.20170209010723297;done=false>>]
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\index.20170209010723297
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory looking to close C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\ [CachedDir<<refCount=0;path=C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\;done=false>>]
[junit4] 2> 1779043 INFO (coreCloseExecutor-4885-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory Closing directory: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001\solr-instance-034\.\collection1\data\
[junit4] 2> 1779044 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[1D55CD45350242B3]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@17f6d9a{/solr,null,UNAVAILABLE}
[junit4] 2> 1779047 INFO (SUITE-TestReplicationHandler-seed#[1D55CD45350242B3]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-5.5-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_1D55CD45350242B3-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=lt, timezone=America/Nipigon
[junit4] 2> NOTE: Windows 8.1 6.3 x86/Oracle Corporation 1.7.0_80 (32-bit)/cpus=3,threads=1,free=128170912,total=315109376
[junit4] 2> NOTE: All tests run in this JVM: [TestDFRSimilarityFactory, DeleteStatusTest, HdfsThreadLeakTest, SimpleMLTQParserTest, TestDocumentBuilder, ClusterStateUpdateTest, HighlighterTest, CollectionsAPISolrJTest, StandardRequestHandlerTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestConfigSetImmutable, CoreSorterTest, DirectUpdateHandlerTest, RecoveryAfterSoftCommitTest, TestEmbeddedSolrServerConstructors, AssignTest, OverseerTaskQueueTest, RecoveryZkTest, TestComplexPhraseQParserPlugin, TestJsonRequest, TestTrieFacet, SimpleFacetsTest, TestRawResponseWriter, DistributedSpellCheckComponentTest, TestSearcherReuse, TestManagedSchemaFieldResource, SmileWriterTest, MBeansHandlerTest, ExitableDirectoryReaderTest, XmlUpdateRequestHandlerTest, TestBlendedInfixSuggestions, TestOverriddenPrefixQueryForCustomFieldType, CleanupOldIndexTest, TestIntervalFaceting, HdfsRecoverLeaseTest, ChangedSchemaMergeTest, BigEndianAscendingWordDeserializerTest, TestSolrDeletionPolicy1, TestPostingsSolrHighlighter, CircularListTest, IndexSchemaTest, TestManagedSchema, QueryElevationComponentTest, SOLR749Test, ConjunctionSolrSpellCheckerTest, TermsComponentTest, AnalysisAfterCoreReloadTest, CheckHdfsIndexTest, TestLRUStatsCache, TestRandomRequestDistribution, RulesTest, DocValuesMultiTest, TimeZoneUtilsTest, DirectSolrSpellCheckerTest, DeleteReplicaTest, SaslZkACLProviderTest, ReplicationFactorTest, TestJmxMonitoredMap, TestFreeTextSuggestions, TestSolrQueryResponse, TestInitParams, PolyFieldTest, TestLazyCores, HLLUtilTest, TestRequestStatusCollectionAPI, TestConfigSetsAPIZkFailure, TestFieldSortValues, TestPerFieldSimilarityWithDefaultOverride, PrimUtilsTest, TestObjectReleaseTracker, SliceStateTest, TestSchemaManager, DeleteInactiveReplicaTest, TestSweetSpotSimilarityFactory, TestTrackingShardHandlerFactory, TestFastLRUCache, URLClassifyProcessorTest, TestSha256AuthenticationProvider, PrimitiveFieldTypeTest, ActionThrottleTest, TestManagedSynonymFilterFactory, TestTolerantSearch, TestDistributedSearch, ConfigSetsAPITest, TestCodecSupport, TestReplicationHandlerBackup, ZkControllerTest, BJQParserTest, HighlighterMaxOffsetTest, TestHashPartitioner, TestClusterStateMutator, DocumentAnalysisRequestHandlerTest, TestRestoreCore, MultiThreadedOCPTest, BufferStoreTest, TestSolrCloudWithKerberosAlt, CoreAdminRequestStatusTest, TestCloudManagedSchema, TriLevelCompositeIdRoutingTest, OverseerTest, TestPKIAuthenticationPlugin, CloneFieldUpdateProcessorFactoryTest, ZkCLITest, XsltUpdateRequestHandlerTest, TestHdfsUpdateLog, TestScoreJoinQPNoScore, TestSolrCLIRunExample, TestDocSet, TestSolrXml, TestDistribDocBasedVersion, TestLuceneMatchVersion, JSONWriterTest, TestOrdValues, TestCloudSchemaless, SchemaVersionSpecificBehaviorTest, TestJsonFacets, TestReplicationHandler]
[junit4] Completed [233/575 (1!)] on J0 in 90.34s, 16 tests, 1 failure <<< FAILURES!
[...truncated 50233 lines...]