Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/3699/ Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed. FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication Error Message: expected:<1> but was:<0> Stack Trace: java.lang.AssertionError: expected:<1> but was:<0> at __randomizedtesting.SeedInfo.seed([A79BEAB82FF795F5:50E804E0E91F3A13]: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.junit.Assert.assertEquals(Assert.java:456) at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1329) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) 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:811) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:462) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) 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 11667 lines...] [junit4] Suite: org.apache.solr.handler.TestReplicationHandler [junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/init-core-data-001 [junit4] 2> 1604567 INFO (SUITE-TestReplicationHandler-seed#[A79BEAB82FF795F5]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) w/ MAC_OS_X supressed clientAuth [junit4] 2> 1604569 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyCommits [junit4] 2> 1604569 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/collection1 [junit4] 2> 1604615 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1604616 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4e92d6d9{/solr,null,AVAILABLE} [junit4] 2> 1604619 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@29a60309{HTTP/1.1,[http/1.1]}{127.0.0.1:54391} [junit4] 2> 1604619 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server Started @1610175ms [junit4] 2> 1604619 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=54391} [junit4] 2> 1604619 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1604620 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 1604620 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 1604620 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1604620 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-09T18:42:36.214Z [junit4] 2> 1604620 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/solr.xml [junit4] 2> 1604638 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/. [junit4] 2> 1604638 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 1604651 WARN (coreLoadExecutor-6391-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 1604651 INFO (coreLoadExecutor-6391-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 1604658 INFO (coreLoadExecutor-6391-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 1604665 INFO (coreLoadExecutor-6391-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 1604669 INFO (coreLoadExecutor-6391-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/./collection1 [junit4] 2> 1604669 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/./collection1/data/] [junit4] 2> 1604670 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1639634601, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 1604679 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 1604680 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1604680 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=15.689453125, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=5.03654005498988, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1604680 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@702caa6[collection1] main] [junit4] 2> 1604680 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-001/collection1/conf [junit4] 2> 1604681 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl [junit4] 2> 1604681 INFO (coreLoadExecutor-6391-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1604681 INFO (searcherExecutor-6392-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@702caa6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1605141 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/collection1 [junit4] 2> 1605163 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1605165 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1f7548dd{/solr,null,AVAILABLE} [junit4] 2> 1605166 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@296a370f{HTTP/1.1,[http/1.1]}{127.0.0.1:54392} [junit4] 2> 1605166 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server Started @1610722ms [junit4] 2> 1605166 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=54392} [junit4] 2> 1605167 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1605167 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 1605167 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 1605167 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1605167 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-09T18:42:36.761Z [junit4] 2> 1605168 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/solr.xml [junit4] 2> 1605229 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/. [junit4] 2> 1605229 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 1605237 WARN (coreLoadExecutor-6401-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 1605237 INFO (coreLoadExecutor-6401-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 1605243 INFO (coreLoadExecutor-6401-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 1605244 INFO (coreLoadExecutor-6401-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 1605245 INFO (coreLoadExecutor-6401-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/./collection1 [junit4] 2> 1605246 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/./collection1/data/] [junit4] 2> 1605247 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1639634601, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 1605253 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 1605253 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1605253 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=15.689453125, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=5.03654005498988, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1605254 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@66ed93e4[collection1] main] [junit4] 2> 1605254 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-002/collection1/conf [junit4] 2> 1605256 INFO (coreLoadExecutor-6401-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms [junit4] 2> 1605256 INFO (searcherExecutor-6402-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@66ed93e4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1605258 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605258 INFO (indexFetcher-6406-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1 [junit4] 2> 1605258 INFO (indexFetcher-6406-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0 [junit4] 2> 1605258 INFO (indexFetcher-6406-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1605762 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1605763 INFO (qtp28261027-13604) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0 [junit4] 2> 1605772 INFO (qtp28261027-13605) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 1605772 INFO (qtp28261027-13605) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@126f1b46 [junit4] 2> 1605775 INFO (qtp28261027-13605) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6fe8136f[collection1] main] [junit4] 2> 1605775 INFO (qtp28261027-13605) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1605775 INFO (searcherExecutor-6392-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@6fe8136f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))} [junit4] 2> 1605776 INFO (qtp28261027-13605) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 3 [junit4] 2> 1605779 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 1605780 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605780 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 1605780 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481308957366 [junit4] 2> 1605780 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1605780 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 1605830 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=49 [junit4] 2> 1605831 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10 [junit4] 2> 1605831 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=89.7197265625, floorSegmentMB=0.375, forceMergeDeletesPctAllowed=20.398354721589598, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 1605832 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1605832 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@ea80a03 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@74fcef2a) [junit4] 2> 1605833 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605834 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605835 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605838 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Asserting_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605841 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Asserting_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605844 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605845 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Asserting_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605846 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605847 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605849 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605850 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1669) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@ea80a03 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@74fcef2a) [junit4] 2> 1605851 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=38.0458984375, floorSegmentMB=1.0302734375, forceMergeDeletesPctAllowed=22.513263973500866, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1605853 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1605854 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@173bd67a[collection1] main] [junit4] 2> 1605855 INFO (searcherExecutor-6402-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@173bd67a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1)))} [junit4] 2> 1605855 INFO (qtp1824522089-13618) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:54391/solr/collection1/replication&command=fetchindex} status=0 QTime=77 [junit4] 2> 1605862 INFO (qtp1824522089-13619) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty1&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0 [junit4] 2> 1605862 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 1605870 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=7 [junit4] 2> 1605871 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605873 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605873 INFO (qtp1824522089-13620) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1 [junit4] 2> 1605874 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605874 INFO (qtp1824522089-13621) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605875 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 1605875 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 1605875 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1605875 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 0 [junit4] 2> 1605877 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 1605878 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605879 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 1605879 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481308957366 [junit4] 2> 1605879 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 1605879 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master. [junit4] 2> 1605879 INFO (qtp1824522089-13622) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:54391/solr/collection1/replication&command=fetchindex} status=0 QTime=2 [junit4] 2> 1605881 INFO (qtp28261027-13603) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 1 [junit4] 2> 1605882 INFO (qtp28261027-13604) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 1605882 INFO (qtp28261027-13604) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@126f1b46 [junit4] 2> 1605884 INFO (qtp28261027-13604) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@20a9d20a[collection1] main] [junit4] 2> 1605884 INFO (qtp28261027-13604) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1605884 INFO (searcherExecutor-6392-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@20a9d20a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1) Uninverting(_1(7.0.0):C1)))} [junit4] 2> 1605884 INFO (qtp28261027-13604) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 2 [junit4] 2> 1605886 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 1605887 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605887 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 3 [junit4] 2> 1605887 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481308957476 [junit4] 2> 1605887 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 1605887 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 1605888 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0 [junit4] 2> 1605888 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 19 [junit4] 2> 1605889 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=89.7197265625, floorSegmentMB=0.375, forceMergeDeletesPctAllowed=20.398354721589598, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@4c687d9c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d566880) [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.doc because it already exists [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tim because it already exists [junit4] 2> 1605890 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 1605891 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tip because it already exists [junit4] 2> 1605891 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 1605891 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 1605891 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Asserting_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605892 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605893 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605894 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Asserting_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605895 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_Asserting_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605896 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605897 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605898 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605899 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605899 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=segments_3&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1605900 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1732) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@4c687d9c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5d566880) [junit4] 2> 1605902 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Exception while updating statistics [junit4] 2> java.io.IOException: file "replication.properties" was already written to [junit4] 2> at org.apache.lucene.store.MockDirectoryWrapper.createOutput(MockDirectoryWrapper.java:654) [junit4] 2> at org.apache.solr.handler.IndexFetcher.logReplicationTimeAndConfFiles(IndexFetcher.java:689) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:501) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:265) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:397) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.lambda$handleRequestBody$0(ReplicationHandler.java:279) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1605903 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=38.0458984375, floorSegmentMB=1.0302734375, forceMergeDeletesPctAllowed=22.513263973500866, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1605938 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1605949 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7cb25a4d[collection1] main] [junit4] 2> 1605949 INFO (searcherExecutor-6402-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7cb25a4d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1) Uninverting(_1(7.0.0):C1)))} [junit4] 2> 1605950 INFO (qtp1824522089-13623) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:54391/solr/collection1/replication&command=fetchindex} status=0 QTime=64 [junit4] 2> 1605951 INFO (qtp1824522089-13616) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty2&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0 [junit4] 2> 1605952 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 1605952 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605953 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605954 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605954 INFO (qtp1824522089-13618) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1605955 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605956 INFO (qtp1824522089-13619) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605957 INFO (qtp28261027-13601) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0 [junit4] 2> 1605957 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 1605957 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@126f1b46 [junit4] 2> 1605959 INFO (qtp28261027-13599) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5f1b929b[collection1] realtime] [junit4] 2> 1605960 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1605960 INFO (qtp28261027-13599) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2}{commit=} 0 2 [junit4] 2> 1605961 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 1605963 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1605963 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 4 [junit4] 2> 1605963 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481308957551 [junit4] 2> 1605963 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 3 [junit4] 2> 1605963 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 1605964 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0 [junit4] 2> 1605964 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 28 [junit4] 2> 1605966 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=89.7197265625, floorSegmentMB=0.375, forceMergeDeletesPctAllowed=20.398354721589598, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 1605967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1605967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1605967 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> 1606971 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1606971 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> 1607981 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1607981 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> 1608987 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1608987 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> 1609992 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1609992 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> 1611002 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1611002 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> 1612007 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1612007 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> 1613018 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1613018 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> 1614024 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1614024 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> 1615024 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1615024 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> 1616035 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 1616035 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> 1617036 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> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@497ca9b9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@397d4a16) [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.doc because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tim because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tip because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.tip because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.doc because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.tim because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists [junit4] 2> 1617036 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists [junit4] 2> 1617039 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617040 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617042 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617043 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_Asserting_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617044 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617044 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617045 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617046 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_Asserting_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617047 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_Asserting_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617048 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=segments_4&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617049 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1795) : 11 secs (163 bytes/sec) to MockDirectoryWrapper(RAMDirectory@497ca9b9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@397d4a16) [junit4] 2> 1617051 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Exception while updating statistics [junit4] 2> java.io.IOException: file "replication.properties" was already written to [junit4] 2> at org.apache.lucene.store.MockDirectoryWrapper.createOutput(MockDirectoryWrapper.java:654) [junit4] 2> at org.apache.solr.handler.IndexFetcher.logReplicationTimeAndConfFiles(IndexFetcher.java:689) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:501) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:265) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:397) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.lambda$handleRequestBody$0(ReplicationHandler.java:279) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1617051 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=38.0458984375, floorSegmentMB=1.0302734375, forceMergeDeletesPctAllowed=22.513263973500866, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1617052 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1617055 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@527629d4[collection1] main] [junit4] 2> 1617055 INFO (searcherExecutor-6402-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@527629d4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1) Uninverting(_1(7.0.0):C1) Uninverting(_2(7.0.0):C1)))} [junit4] 2> 1617055 INFO (qtp1824522089-13620) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:54391/solr/collection1/replication&command=fetchindex} status=0 QTime=11094 [junit4] 2> 1617058 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty3&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1617059 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs [junit4] 2> 1617062 INFO (qtp1824522089-13621) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:empty3&sort=id+desc&wt=javabin&version=2} hits=1 status=0 QTime=0 [junit4] 2> 1617062 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 1617063 INFO (qtp28261027-13601) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0 [junit4] 2> 1617063 INFO (qtp28261027-13602) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 1617063 INFO (qtp28261027-13602) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@126f1b46 [junit4] 2> 1617065 INFO (qtp28261027-13602) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d25de44[collection1] main] [junit4] 2> 1617065 INFO (qtp28261027-13602) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 1617065 INFO (searcherExecutor-6392-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5d25de44[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1) Uninverting(_1(7.0.0):C1) Uninverting(_2(7.0.0):C1) Uninverting(_3(7.0.0):C1)))} [junit4] 2> 1617066 INFO (qtp28261027-13602) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 2 [junit4] 2> 1617070 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 1617071 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1617072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 5 [junit4] 2> 1617072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481308968657 [junit4] 2> 1617072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 4 [junit4] 2> 1617072 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 1617073 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0 [junit4] 2> 1617073 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 37 [junit4] 2> 1617075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=89.7197265625, floorSegmentMB=0.375, forceMergeDeletesPctAllowed=20.398354721589598, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 1617075 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1af475cc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14552039) [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.doc because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tim because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0_Asserting_0.tip because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.tip because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.doc because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1_Asserting_0.tim because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists [junit4] 2> 1617076 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.nvd because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.si because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fdt because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_Asserting_0.tip because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fnm because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.nvm because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.fdx because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_Asserting_0.doc because it already exists [junit4] 2> 1617077 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2_Asserting_0.tim because it already exists [junit4] 2> 1617077 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617079 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617080 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617081 INFO (qtp28261027-13601) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_Asserting_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617082 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617083 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617084 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_Asserting_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617085 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617086 INFO (qtp28261027-13606) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_Asserting_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617104 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=segments_5&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 1617104 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1858) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@1af475cc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@14552039) [junit4] 2> 1617106 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Exception while updating statistics [junit4] 2> java.io.IOException: file "replication.properties" was already written to [junit4] 2> at org.apache.lucene.store.MockDirectoryWrapper.createOutput(MockDirectoryWrapper.java:654) [junit4] 2> at org.apache.solr.handler.IndexFetcher.logReplicationTimeAndConfFiles(IndexFetcher.java:689) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:501) [junit4] 2> at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:265) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:397) [junit4] 2> at org.apache.solr.handler.ReplicationHandler.lambda$handleRequestBody$0(ReplicationHandler.java:279) [junit4] 2> at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1617106 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=38.0458984375, floorSegmentMB=1.0302734375, forceMergeDeletesPctAllowed=22.513263973500866, segmentsPerTier=32.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1617107 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 1617108 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1aea1c86[collection1] main] [junit4] 2> 1617108 INFO (searcherExecutor-6402-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1aea1c86[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C1) Uninverting(_1(7.0.0):C1) Uninverting(_2(7.0.0):C1) Uninverting(_3(7.0.0):C1)))} [junit4] 2> 1617108 INFO (qtp1824522089-13621) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:54391/solr/collection1/replication&command=fetchindex} status=0 QTime=38 [junit4] 2> 1617110 INFO (qtp28261027-13599) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&sort=id+desc&wt=javabin&version=2} hits=4 status=0 QTime=0 [junit4] 2> 1617111 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs [junit4] 2> 1617112 INFO (qtp1824522089-13623) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=name:(empty1+empty2+empty3+empty4)&sort=id+desc&wt=javabin&version=2} hits=4 status=0 QTime=0 [junit4] 2> 1617113 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs [junit4] 2> 1617121 INFO (qtp28261027-13602) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=5 [junit4] 2> 1617122 INFO (qtp28261027-13604) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1617124 INFO (qtp28261027-13603) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={slave=false&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=0 [junit4] 2> 1617124 INFO (qtp1824522089-13623) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1 [junit4] 2> 1617125 INFO (qtp28261027-13605) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1617126 INFO (qtp1824522089-13618) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=assertVersions&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1617126 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEmptyCommits [junit4] 2> 1617127 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@29a60309{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1617127 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=217806580 [junit4] 2> 1617128 INFO (coreCloseExecutor-6411-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@581500a9 [junit4] 2> 1617130 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4e92d6d9{/solr,null,UNAVAILABLE} [junit4] 2> 1617139 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@296a370f{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1617139 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=536446861 [junit4] 2> 1617140 INFO (coreCloseExecutor-6413-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@63d43794 [junit4] 2> 1617147 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1f7548dd{/solr,null,UNAVAILABLE} [junit4] 2> 1617153 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestIndexFetchWithMasterUrl [junit4] 2> 1617153 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/collection1 [junit4] 2> 1617160 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1617161 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3172091{/solr,null,AVAILABLE} [junit4] 2> 1617161 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@52681c51{HTTP/1.1,[http/1.1]}{127.0.0.1:54417} [junit4] 2> 1617161 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server Started @1622718ms [junit4] 2> 1617161 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/collection1/data, hostContext=/solr, hostPort=54417} [junit4] 2> 1617162 ERROR (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1617163 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 1617163 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 1617163 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1617163 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-09T18:42:48.757Z [junit4] 2> 1617163 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/solr.xml [junit4] 2> 1617175 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/. [junit4] 2> 1617175 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 1617183 WARN (coreLoadExecutor-6420-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 1617183 INFO (coreLoadExecutor-6420-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 1617193 INFO (coreLoadExecutor-6420-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 1617195 INFO (coreLoadExecutor-6420-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 1617196 INFO (coreLoadExecutor-6420-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/./collection1 [junit4] 2> 1617196 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/./collection1/data/] [junit4] 2> 1617202 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1639634601, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 1617216 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 1617216 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1617217 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=15.689453125, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=5.03654005498988, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1617217 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4cae3379[collection1] main] [junit4] 2> 1617218 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-003/collection1/conf [junit4] 2> 1617218 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl [junit4] 2> 1617219 INFO (coreLoadExecutor-6420-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 1617219 INFO (searcherExecutor-6421-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4cae3379[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1617680 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/collection1 [junit4] 2> 1617703 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1617705 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22b1229e{/solr,null,AVAILABLE} [junit4] 2> 1617706 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4f28a19d{HTTP/1.1,[http/1.1]}{127.0.0.1:54418} [junit4] 2> 1617706 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server Started @1623262ms [junit4] 2> 1617706 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/collection1/data, hostContext=/solr, hostPort=54418} [junit4] 2> 1617706 ERROR (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 1617707 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.0.0 [junit4] 2> 1617707 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 1617707 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 1617707 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2016-12-09T18:42:49.301Z [junit4] 2> 1617708 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/solr.xml [junit4] 2> 1617724 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/. [junit4] 2> 1617724 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 1617742 WARN (coreLoadExecutor-6430-thread-1) [ ] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is deprecated, use <mergePolicyFactory> instead. [junit4] 2> 1617743 INFO (coreLoadExecutor-6430-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0 [junit4] 2> 1617749 INFO (coreLoadExecutor-6430-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 1617754 INFO (coreLoadExecutor-6430-thread-1) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 1617761 INFO (coreLoadExecutor-6430-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/./collection1 [junit4] 2> 1617761 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/collection1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/./collection1/data/] [junit4] 2> 1617763 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1639634601, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 1617776 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 1617776 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 1617776 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=38, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=15.689453125, floorSegmentMB=1.54296875, forceMergeDeletesPctAllowed=5.03654005498988, segmentsPerTier=17.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 1617777 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@262b0b60[collection1] main] [junit4] 2> 1617777 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001/solr-instance-004/collection1/conf [junit4] 2> 1617778 INFO (coreLoadExecutor-6430-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms [junit4] 2> 1617778 INFO (searcherExecutor-6431-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@262b0b60[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 1618026 INFO (qtp549540140-13651) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1618026 INFO (indexFetcher-6435-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1 [junit4] 2> 1618026 INFO (indexFetcher-6435-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0 [junit4] 2> 1618026 INFO (indexFetcher-6435-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 1618229 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4f28a19d{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1618229 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1204828933 [junit4] 2> 1618230 INFO (coreCloseExecutor-6436-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3d5f40a5 [junit4] 2> 1618232 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@22b1229e{/solr,null,UNAVAILABLE} [junit4] 2> 1618234 INFO (TEST-TestReplicationHandler.doTestIndexFetchWithMasterUrl-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 1618236 INFO (TEST-TestR [...truncated too long message...] ] o.a.s.h.TestReplicationHandler Waiting for 1 docs [junit4] 2> 1712746 INFO (qtp810554522-14627) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:2001&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1712746 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waiting for 1 docs [junit4] 2> 1712855 INFO (qtp810554522-14631) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:2001&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1712855 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waiting for 1 docs [junit4] 2> 1712951 INFO (qtp1241233943-14608) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 1712951 INFO (indexFetcher-7036-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 1712951 INFO (indexFetcher-7036-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1481309031724 [junit4] 2> 1712952 INFO (indexFetcher-7036-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 1712952 INFO (indexFetcher-7036-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master. [junit4] 2> 1712966 INFO (qtp810554522-14632) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:2001&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1712966 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waiting for 1 docs [junit4] 2> 1713076 INFO (qtp810554522-14633) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=id:2001&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 1713076 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.h.TestReplicationHandler Waited for 30000ms and found 0 docs [junit4] 2> 1713077 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.SolrTestCaseJ4 ###Ending doTestIndexAndConfigAliasReplication [junit4] 2> 1713078 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@55524bd4{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1713078 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=158562197 [junit4] 2> 1713079 INFO (coreCloseExecutor-7038-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@e00be9a [junit4] 2> 1713080 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@42fb399f{/solr,null,UNAVAILABLE} [junit4] 2> 1713082 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1b058bbe{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 1713082 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=2119553471 [junit4] 2> 1713083 INFO (coreCloseExecutor-7040-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@2943edea [junit4] 2> 1713084 INFO (TEST-TestReplicationHandler.doTestIndexAndConfigAliasReplication-seed#[A79BEAB82FF795F5]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4e10e91e{/solr,null,UNAVAILABLE} [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestReplicationHandler -Dtests.method=doTestIndexAndConfigAliasReplication -Dtests.seed=A79BEAB82FF795F5 -Dtests.slow=true -Dtests.locale=da-DK -Dtests.timezone=Africa/Timbuktu -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] FAILURE 35.8s J1 | TestReplicationHandler.doTestIndexAndConfigAliasReplication <<< [junit4] > Throwable #1: java.lang.AssertionError: expected:<1> but was:<0> [junit4] > at __randomizedtesting.SeedInfo.seed([A79BEAB82FF795F5:50E804E0E91F3A13]:0) [junit4] > at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1329) [junit4] > at java.lang.Thread.run(Thread.java:745) [junit4] 2> 1713088 INFO (SUITE-TestReplicationHandler-seed#[A79BEAB82FF795F5]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore [junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_A79BEAB82FF795F5-001 [junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {name=PostingsFormat(name=Asserting), id=PostingsFormat(name=Asserting), newname=PostingsFormat(name=Asserting)}, docValues:{}, maxPointsInLeafNode=912, maxMBSortInHeap=7.03983547215896, sim=RandomSimilarity(queryNorm=true): {}, locale=da-DK, timezone=Africa/Timbuktu [junit4] 2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 1.8.0_102 (64-bit)/cpus=3,threads=1,free=151369432,total=496996352 [junit4] 2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, UUIDFieldTest, PeerSyncReplicationTest, TestIndexSearcher, TestCloudManagedSchema, TestAtomicUpdateErrorCases, ShowFileRequestHandlerTest, TestFilteredDocIdSet, DeleteNodeTest, SuggesterWFSTTest, QueryParsingTest, TestJmxMonitoredMap, NotRequiredUniqueKeyTest, SpellingQueryConverterTest, TestLegacyNumericRangeQueryBuilder, PeerSyncWithIndexFingerprintCachingTest, RankQueryTest, TestSimpleTrackingShardHandler, TestSolrCLIRunExample, NoCacheHeaderTest, BadComponentTest, TestSQLHandler, StatsReloadRaceTest, BasicZkTest, TestDeleteCollectionOnDownNodes, DistributedVersionInfoTest, SmileWriterTest, CdcrUpdateLogTest, TestMiniSolrCloudCluster, ForceLeaderTest, CursorMarkTest, TestRecovery, SpellPossibilityIteratorTest, TestSolrIndexConfig, ZkStateWriterTest, CloudMLTQParserTest, TestSubQueryTransformerDistrib, TestCrossCoreJoin, TestManagedResourceStorage, FileBasedSpellCheckerTest, TestConfig, TestAnalyzeInfixSuggestions, TestSuggestSpellingConverter, TestUnifiedSolrHighlighter, TestHighFrequencyDictionaryFactory, HdfsDirectoryTest, TestImplicitCoreProperties, TestDFRSimilarityFactory, TestSolrQueryParserResource, ChaosMonkeySafeLeaderTest, TestFieldCacheReopen, SliceStateTest, TestCloudPseudoReturnFields, ChangedSchemaMergeTest, TestSolrDeletionPolicy2, TestLMJelinekMercerSimilarityFactory, TestCustomSort, TestValueSourceCache, TestLeaderElectionZkExpiry, SuggesterTSTTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestDistributedMissingSort, SolrCloudExampleTest, TestSimpleQParserPlugin, OpenCloseCoreStressTest, TestSSLRandomization, TestReRankQParserPlugin, TestEmbeddedSolrServerConstructors, TestJavabinTupleStreamParser, FullSolrCloudDistribCmdsTest, SimpleCollectionCreateDeleteTest, TestSchemaNameResource, TestZkChroot, TestStandardQParsers, TestFieldCacheVsDocValues, TestSubQueryTransformer, BasicAuthIntegrationTest, TestFiltering, TestComponentsName, TestSolrCoreSnapshots, RemoteQueryErrorTest, TestSolrCoreProperties, CollectionsAPISolrJTest, TestExceedMaxTermLength, TestScoreJoinQPScore, HdfsDirectoryFactoryTest, ExplicitHLLTest, TestClassicSimilarityFactory, BigEndianAscendingWordSerializerTest, ManagedSchemaRoundRobinCloudTest, TestSolrXml, TestStressRecovery, TestCollapseQParserPlugin, TestPHPSerializedResponseWriter, StatsComponentTest, HighlighterConfigTest, ConvertedLegacyTest, TestUseDocValuesAsStored, ShardRoutingCustomTest, TestNumericTerms64, TestSha256AuthenticationProvider, TestConfigSetsAPIZkFailure, TestExactStatsCache, TestConfigSetsAPI, TestIndexingPerformance, CacheHeaderTest, BasicFunctionalityTest, TestBlobHandler, SecurityConfHandlerTest, HdfsSyncSliceTest, ShufflingReplicaListTransformerTest, TestClusterProperties, TestAnalyzedSuggestions, TestReload, TestDownShardTolerantSearch, TestManagedStopFilterFactory, DistributedExpandComponentTest, TestMacros, TestDynamicFieldCollectionResource, DocValuesMissingTest, TestSolrQueryResponse, CollectionReloadTest, GraphQueryTest, TestSolr4Spatial2, BadCopyFieldTest, SharedFSAutoReplicaFailoverTest, TestRawResponseWriter, TestRequestForwarding, CdcrVersionReplicationTest, TestFoldingMultitermQuery, CloneFieldUpdateProcessorFactoryTest, HdfsTlogReplayBufferedWhileIndexingTest, HdfsRecoveryZkTest, FacetPivotSmallTest, TestDocSet, DistributedQueryComponentOptimizationTest, ResourceLoaderTest, TestDistribIDF, TestNamedUpdateProcessors, LeaderElectionIntegrationTest, TestCustomStream, BadIndexSchemaTest, SpatialRPTFieldTypeTest, TestManagedSchemaThreadSafety, TestFieldCacheSort, TestReversedWildcardFilterFactory, HdfsNNFailoverTest, TestOmitPositions, TermVectorComponentDistributedTest, TestWriterPerf, DateMathParserTest, RuleEngineTest, TestSizeLimitedDistributedMap, DirectoryFactoryTest, SuggesterTest, AsyncCallRequestStatusResponseTest, TestSolrQueryParser, DistributedFacetPivotSmallAdvancedTest, TestJoin, DistributedFacetPivotLargeTest, LoggingHandlerTest, BasicDistributedZkTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, SyncSliceTest, TestReplicationHandler] [junit4] Completed [338/659 (1!)] on J1 in 108.54s, 15 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 63416 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org