Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-7.x/192/
1 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.handler.TestReplicationHandler Error Message: ObjectTracker found 5 object(s) that were not released!!! [SolrCore, InternalHttpClient, MockDirectoryWrapper, MockDirectoryWrapper, MockDirectoryWrapper] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1040) at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:289) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:298) at org.apache.solr.handler.IndexFetcher.createHttpClient(IndexFetcher.java:248) at org.apache.solr.handler.IndexFetcher.<init>(IndexFetcher.java:290) at org.apache.solr.handler.ReplicationHandler.inform(ReplicationHandler.java:1190) at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:696) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:988) at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:352) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:730) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:955) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:864) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1047) at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:643) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:192) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Stack Trace: java.lang.AssertionError: ObjectTracker found 5 object(s) that were not released!!! [SolrCore, InternalHttpClient, MockDirectoryWrapper, MockDirectoryWrapper, MockDirectoryWrapper] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1040) at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:289) at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:298) at org.apache.solr.handler.IndexFetcher.createHttpClient(IndexFetcher.java:248) at org.apache.solr.handler.IndexFetcher.<init>(IndexFetcher.java:290) at org.apache.solr.handler.ReplicationHandler.inform(ReplicationHandler.java:1190) at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:696) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:988) at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:352) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:730) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:955) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:864) at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1047) at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:643) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:192) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([B3CB0D2BE889AEA6]:0) at org.junit.Assert.fail(Assert.java:93) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertNull(Assert.java:551) at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:303) at sun.reflect.GeneratedMethodAccessor22.invoke(Unknown Source) 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:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:897) 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:368) at java.lang.Thread.run(Thread.java:748) Build Log: [...truncated 14338 lines...] [junit4] Suite: org.apache.solr.handler.TestReplicationHandler [junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/init-core-data-001 [junit4] 2> 2065841 WARN (SUITE-TestReplicationHandler-seed#[B3CB0D2BE889AEA6]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=469 numCloses=469 [junit4] 2> 2065841 INFO (SUITE-TestReplicationHandler-seed#[B3CB0D2BE889AEA6]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 2065842 INFO (SUITE-TestReplicationHandler-seed#[B3CB0D2BE889AEA6]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) [junit4] 2> 2065842 INFO (SUITE-TestReplicationHandler-seed#[B3CB0D2BE889AEA6]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 2065854 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyCommits [junit4] 2> 2065855 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/collection1 [junit4] 2> 2065858 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T13:27:37-08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2065906 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2065906 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2065906 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session Scavenging every 660000ms [junit4] 2> 2065907 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@688d85cd{/solr,null,AVAILABLE} [junit4] 2> 2065907 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3c66203c{HTTP/1.1,[http/1.1]}{127.0.0.1:34436} [junit4] 2> 2065907 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.Server Started @2065961ms [junit4] 2> 2065907 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=34436} [junit4] 2> 2065908 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0 [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-05T07:50:20.660Z [junit4] 2> 2065908 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/solr.xml [junit4] 2> 2065912 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 2065912 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 2065913 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 2066225 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066258 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066258 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066267 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/. [junit4] 2> 2066267 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2066271 INFO (coreLoadExecutor-6128-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 2066287 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2066308 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2066316 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 2066316 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/./collection1, trusted=true [junit4] 2> 2066316 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066316 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2066316 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/./collection1/data/] [junit4] 2> 2066320 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=39, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7431806441911083] [junit4] 2> 2066406 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2066406 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2066406 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=49.0283203125, floorSegmentMB=2.0673828125, forceMergeDeletesPctAllowed=21.932180843130684, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 2066407 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@114ec550[collection1] main] [junit4] 2> 2066407 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-001/collection1/conf [junit4] 2> 2066408 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl [junit4] 2> 2066408 INFO (coreLoadExecutor-6128-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2066416 INFO (searcherExecutor-6129-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@114ec550[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2066416 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/collection1 [junit4] 2> 2066418 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 2017-11-21T13:27:37-08:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8 [junit4] 2> 2066419 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 2066419 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 2066419 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session Scavenging every 600000ms [junit4] 2> 2066419 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2df1656f{/solr,null,AVAILABLE} [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@4b2e131b{HTTP/1.1,[http/1.1]}{127.0.0.1:38835} [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.Server Started @2066473ms [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=38835} [junit4] 2> 2066420 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.4.0 [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2018-04-05T07:50:21.172Z [junit4] 2> 2066420 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/solr.xml [junit4] 2> 2066424 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 2066424 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 2066425 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 2066508 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066533 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066533 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066546 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/. [junit4] 2> 2066546 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 2066562 INFO (coreLoadExecutor-6138-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 2066574 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.4.0 [junit4] 2> 2066588 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 2066590 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 2066590 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/./collection1, trusted=true [junit4] 2> 2066592 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@76291b13 [junit4] 2> 2066592 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2066592 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/./collection1/data/] [junit4] 2> 2066598 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=39, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7431806441911083] [junit4] 2> 2066877 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2066877 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2066878 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=40, maxMergedSegmentMB=49.0283203125, floorSegmentMB=2.0673828125, forceMergeDeletesPctAllowed=21.932180843130684, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0 [junit4] 2> 2066879 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@72dc346[collection1] main] [junit4] 2> 2066879 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/checkout/solr/build/solr-core/test/J1/temp/solr.handler.TestReplicationHandler_B3CB0D2BE889AEA6-001/solr-instance-002/collection1/conf [junit4] 2> 2066886 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms [junit4] 2> 2066886 INFO (coreLoadExecutor-6138-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 2066888 INFO (searcherExecutor-6139-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@72dc346[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2066903 INFO (qtp268002353-20939) [ 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> 2066903 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0 [junit4] 2> 2066904 INFO (qtp268002353-20939) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2066904 INFO (qtp268002353-20939) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@76963d4f commitCommandVersion:0 [junit4] 2> 2066907 INFO (qtp268002353-20939) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@b872230[collection1] main] [junit4] 2> 2066907 INFO (qtp268002353-20939) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2066908 INFO (searcherExecutor-6129-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@b872230[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1)))} [junit4] 2> 2066908 INFO (qtp268002353-20939) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 4 [junit4] 2> 2066919 WARN (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 2066922 INFO (qtp268002353-20939) [ 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> 2066926 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 2066926 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's version: 1522914621656 [junit4] 2> 2066926 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 2066926 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 2066926 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 2066928 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=1 [junit4] 2> 2066929 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 10 [junit4] 2> 2066945 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=63.8134765625, floorSegmentMB=0.9326171875, forceMergeDeletesPctAllowed=28.04361265789452, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2066946 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2066946 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@3a7a1b31 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30f663fa; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2066947 INFO (qtp268002353-20945) [ 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> 2066954 INFO (qtp268002353-20944) [ 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> 2066957 INFO (qtp268002353-20945) [ 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> 2066958 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_BlockTreeOrds_0.tio&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2066958 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_BlockTreeOrds_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2066959 INFO (qtp268002353-20944) [ 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> 2066960 INFO (qtp268002353-20945) [ 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> 2066960 INFO (qtp268002353-20944) [ 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> 2066961 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_BlockTreeOrds_0.tipo&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2066962 INFO (qtp268002353-20944) [ 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> 2066962 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Bytes downloaded: 1746, Bytes skipped downloading: 0 [junit4] 2> 2066962 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1746) : 0 secs (null bytes/sec) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@3a7a1b31 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30f663fa; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2066966 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 2066967 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2066967 INFO (explicit-fetchindex-cmd) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@25802ce7[collection1] main] [junit4] 2> 2066968 INFO (searcherExecutor-6139-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@25802ce7[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1)))} [junit4] 2> 2066968 INFO (qtp205604491-20956) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:34436/solr/collection1/replication&command=fetchindex} status=0 QTime=49 [junit4] 2> 2066981 INFO (qtp268002353-20945) [ 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> 2066981 INFO (indexFetcher-6143-thread-1) [ ] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 2066981 INFO (indexFetcher-6143-thread-1) [ ] o.a.s.h.IndexFetcher Master's version: 1522914621656 [junit4] 2> 2066981 INFO (indexFetcher-6143-thread-1) [ ] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 2066981 INFO (indexFetcher-6143-thread-1) [ ] o.a.s.h.IndexFetcher Slave's version: 1522914621656 [junit4] 2> 2066981 INFO (indexFetcher-6143-thread-1) [ ] o.a.s.h.IndexFetcher Slave in sync with master. [junit4] 2> 2067013 INFO (qtp205604491-20960) [ 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> 2067013 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 2067014 INFO (qtp268002353-20941) [ 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> 2067014 INFO (qtp268002353-20945) [ 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> 2067015 INFO (qtp268002353-20944) [ 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> 2067015 INFO (qtp205604491-20955) [ 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> 2067015 INFO (qtp268002353-20941) [ 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> 2067016 INFO (qtp205604491-20961) [ 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> 2067016 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2067016 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit. [junit4] 2> 2067016 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2067016 INFO (qtp268002353-20944) [ 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> 2067022 WARN (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 2067023 INFO (qtp268002353-20945) [ 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> 2067023 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 2067023 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's version: 1522914621656 [junit4] 2> 2067023 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 2067023 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's version: 1522914621656 [junit4] 2> 2067023 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave in sync with master. [junit4] 2> 2067023 INFO (qtp205604491-20958) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:34436/solr/collection1/replication&command=fetchindex} status=0 QTime=6 [junit4] 2> 2067024 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 0 [junit4] 2> 2067024 INFO (qtp268002353-20945) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2067024 INFO (qtp268002353-20945) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@76963d4f commitCommandVersion:0 [junit4] 2> 2067029 INFO (qtp268002353-20945) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7d8ab30f[collection1] main] [junit4] 2> 2067030 INFO (qtp268002353-20945) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2067031 INFO (searcherExecutor-6129-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7d8ab30f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1) Uninverting(_1(7.4.0):C1)))} [junit4] 2> 2067031 INFO (qtp268002353-20945) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={commit=true&wt=javabin&version=2}{commit=} 0 6 [junit4] 2> 2067042 WARN (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 2067043 INFO (qtp268002353-20944) [ 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> 2067043 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's generation: 3 [junit4] 2> 2067043 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's version: 1522914621776 [junit4] 2> 2067043 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 2067043 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's version: 1522914621656 [junit4] 2> 2067043 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 2067044 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0 [junit4] 2> 2067044 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 19 [junit4] 2> 2067045 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=63.8134765625, floorSegmentMB=0.9326171875, forceMergeDeletesPctAllowed=28.04361265789452, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2067050 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@24e56885 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18224393; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 2067051 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2067051 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_BlockTreeOrds_0.tipo&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2067089 INFO (qtp268002353-20945) [ 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> 2067090 INFO (qtp268002353-20944) [ 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> 2067090 INFO (qtp268002353-20945) [ 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> 2067091 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_BlockTreeOrds_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2067092 INFO (qtp268002353-20945) [ 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> 2067092 INFO (qtp268002353-20944) [ 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> 2067093 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1_BlockTreeOrds_0.tio&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2067095 INFO (qtp268002353-20944) [ 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> 2067096 INFO (qtp268002353-20945) [ 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> 2067096 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Bytes downloaded: 1808, Bytes skipped downloading: 0 [junit4] 2> 2067096 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1808) : 0 secs (null bytes/sec) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@24e56885 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18224393; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2067136 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 2067137 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2067137 INFO (explicit-fetchindex-cmd) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3acbe5df[collection1] main] [junit4] 2> 2067138 INFO (searcherExecutor-6139-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3acbe5df[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1) Uninverting(_1(7.4.0):C1)))} [junit4] 2> 2067139 INFO (qtp205604491-20961) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:34436/solr/collection1/replication&command=fetchindex} status=0 QTime=107 [junit4] 2> 2067140 INFO (qtp205604491-20955) [ 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> 2067140 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 2067140 INFO (qtp268002353-20941) [ 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> 2067140 INFO (qtp268002353-20945) [ 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> 2067141 INFO (qtp268002353-20944) [ 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> 2067141 INFO (qtp205604491-20961) [ 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> 2067142 INFO (qtp268002353-20941) [ 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> 2067142 INFO (qtp205604491-20955) [ 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> 2067144 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 2 [junit4] 2> 2067144 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2067145 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@76963d4f commitCommandVersion:0 [junit4] 2> 2067146 INFO (qtp268002353-20941) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3931d2f8[collection1] realtime] [junit4] 2> 2067146 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2067146 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={openSearcher=false&commit=true&wt=javabin&version=2}{commit=} 0 1 [junit4] 2> 2067161 WARN (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 2067162 INFO (qtp268002353-20945) [ 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> 2067167 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's generation: 4 [junit4] 2> 2067167 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's version: 1522914621897 [junit4] 2> 2067167 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's generation: 3 [junit4] 2> 2067167 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's version: 1522914621776 [junit4] 2> 2067168 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 2067169 INFO (qtp268002353-20941) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0 [junit4] 2> 2067169 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 28 [junit4] 2> 2067170 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=63.8134765625, floorSegmentMB=0.9326171875, forceMergeDeletesPctAllowed=28.04361265789452, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2067173 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2067174 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2067174 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2068174 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2068174 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2069175 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2069175 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2070175 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2070175 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2071176 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2071176 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2072176 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2072176 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2073177 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2073177 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2074177 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2074177 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2075178 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2075178 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2076178 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2076178 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2077179 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Found unused file: segments_2 [junit4] 2> 2077179 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able [junit4] 2> 2078179 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher IndexFetcher slept for 11000ms for unused lucene index files to be delete-able [junit4] 2> 2078179 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@6e65f2e5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@29dfa632; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2078180 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists [junit4] 2> 2078182 INFO (qtp268002353-20945) [ 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> 2078190 INFO (qtp268002353-20941) [ 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> 2078191 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_BlockTreeOrds_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078191 INFO (qtp268002353-20941) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_BlockTreeOrds_0.tio&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078192 INFO (qtp268002353-20945) [ 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> 2078198 INFO (qtp268002353-20941) [ 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> 2078199 INFO (qtp268002353-20945) [ 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> 2078200 INFO (qtp268002353-20941) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2_BlockTreeOrds_0.tipo&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078200 INFO (qtp268002353-20945) [ 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> 2078201 INFO (qtp268002353-20941) [ 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> 2078201 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Bytes downloaded: 1870, Bytes skipped downloading: 0 [junit4] 2> 2078201 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1870) : 11 secs (170 bytes/sec) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@6e65f2e5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@29dfa632; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2078203 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 2078203 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2078204 INFO (explicit-fetchindex-cmd) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@c6774a2[collection1] main] [junit4] 2> 2078205 INFO (searcherExecutor-6139-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@c6774a2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1) Uninverting(_1(7.4.0):C1) Uninverting(_2(7.4.0):C1)))} [junit4] 2> 2078205 INFO (qtp205604491-20958) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:34436/solr/collection1/replication&command=fetchindex} status=0 QTime=11058 [junit4] 2> 2078207 INFO (qtp268002353-20944) [ 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> 2078207 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs [junit4] 2> 2078209 INFO (qtp205604491-20961) [ 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> 2078209 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs [junit4] 2> 2078209 INFO (qtp268002353-20941) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0 [junit4] 2> 2078210 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 2078210 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@76963d4f commitCommandVersion:0 [junit4] 2> 2078211 INFO (qtp268002353-20944) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@7f4afe85[collection1] main] [junit4] 2> 2078211 INFO (qtp268002353-20944) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 2078212 INFO (searcherExecutor-6129-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7f4afe85[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1) Uninverting(_1(7.4.0):C1) Uninverting(_2(7.4.0):C1) Uninverting(_3(7.4.0):C1)))} [junit4] 2> 2078212 INFO (qtp268002353-20944) [ 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> 2078213 WARN (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix [junit4] 2> 2078214 INFO (qtp268002353-20945) [ 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> 2078214 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's generation: 5 [junit4] 2> 2078214 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Master's version: 1522914632962 [junit4] 2> 2078214 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's generation: 4 [junit4] 2> 2078214 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Slave's version: 1522914621897 [junit4] 2> 2078214 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 2078265 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=51 [junit4] 2> 2078266 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Number of files in latest index in master: 37 [junit4] 2> 2078267 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=63.8134765625, floorSegmentMB=0.9326171875, forceMergeDeletesPctAllowed=28.04361265789452, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0 [junit4] 2> 2078267 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4316712c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41e8b660; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvd because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdx because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fdt because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.fnm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0.nvm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _0_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.nvd because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fdx because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fnm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.nvm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _1.fdt because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.nvd because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.si because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2_BlockTreeOrds_0.doc because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2_BlockTreeOrds_0.tio because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.fdt because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.fnm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.nvm because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2_BlockTreeOrds_0.tipo because it already exists [junit4] 2> 2078268 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Skipping download for _2.fdx because it already exists [junit4] 2> 2078269 INFO (qtp268002353-20945) [ 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> 2078270 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_BlockTreeOrds_0.tipo&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078271 INFO (qtp268002353-20945) [ 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> 2078272 INFO (qtp268002353-20944) [ 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> 2078273 INFO (qtp268002353-20945) [ 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> 2078274 INFO (qtp268002353-20944) [ 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> 2078275 INFO (qtp268002353-20945) [ 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> 2078276 INFO (qtp268002353-20944) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_BlockTreeOrds_0.tio&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078276 INFO (qtp268002353-20945) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3_BlockTreeOrds_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 2078282 INFO (qtp268002353-20944) [ 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> 2078283 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Bytes downloaded: 1932, Bytes skipped downloading: 0 [junit4] 2> 2078283 INFO (explicit-fetchindex-cmd) [ ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1932) : 0 secs (null bytes/sec) to MockDirectoryWrapper(NRTCachingDirectory(RAMDirectory@4316712c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@41e8b660; maxCacheMB=0.1611328125 maxMergeSizeMB=0.7431640625)) [junit4] 2> 2078286 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=42, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0] [junit4] 2> 2078287 INFO (explicit-fetchindex-cmd) [ ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 2078341 INFO (explicit-fetchindex-cmd) [ ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7effe3ca[collection1] main] [junit4] 2> 2078342 INFO (searcherExecutor-6139-thread-1) [ ] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@7effe3ca[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.4.0):C1) Uninverting(_1(7.4.0):C1) Uninverting(_2(7.4.0):C1) Uninverting(_3(7.4.0):C1)))} [junit4] 2> 2078345 INFO (qtp205604491-20955) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:34436/solr/collection1/replication&command=fetchindex} status=0 QTime=132 [junit4] 2> 2078347 INFO (qtp268002353-20941) [ 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> 2078347 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs [junit4] 2> 2078348 INFO (qtp205604491-20958) [ 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> 2078348 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs [junit4] 2> 2078348 INFO (qtp268002353-20944) [ 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> 2078349 INFO (qtp268002353-20941) [ 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> 2078350 INFO (qtp268002353-20945) [ 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> 2078350 INFO (qtp205604491-20955) [ 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> 2078350 INFO (qtp268002353-20944) [ 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> 2078350 INFO (qtp205604491-20958) [ 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> 2078351 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEmptyCommits [junit4] 2> 2078351 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3c66203c{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 2078351 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=876103551 [junit4] 2> 2078352 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 2078352 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3f10ade1: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@14f2c5b2 [junit4] 2> 2078356 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 2078356 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@247f4d82: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@70aff4d3 [junit4] 2> 2078359 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 2078359 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@24a49b47: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@67118203 [junit4] 2> 2078410 INFO (coreCloseExecutor-6148-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@57ac64ba [junit4] 2> 2078410 INFO (coreCloseExecutor-6148-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=57ac64ba [junit4] 2> 2078410 INFO (coreCloseExecutor-6148-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1370b10d: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@1510c53c [junit4] 2> 2078416 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@688d85cd{/solr,null,UNAVAILABLE} [junit4] 2> 2078416 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.session Stopped scavenging [junit4] 2> 2078422 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@4b2e131b{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 2078423 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1476992021 [junit4] 2> 2078423 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 2078423 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1bcd1e23: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@1d67ccd5 [junit4] 2> 2078428 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[B3CB0D2BE889AEA6]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 2078428 INFO (TEST [...truncated too long message...] est, SOLR749Test, AutoScalingHandlerTest, TestOrdValues, TestCloudRecovery, PeerSyncReplicationTest, TestTriggerIntegration, LIROnShardRestartTest, TestLRUCache, SaslZkACLProviderTest, TestLuceneIndexBackCompat, TestFieldCacheVsDocValues, TestSortableTextField, CdcrBootstrapTest, RestoreTriggerStateTest, ShardRoutingCustomTest, TestHdfsCloudBackupRestore, OverseerTest, HdfsLockFactoryTest, AssignTest, TestExactSharedStatsCache, TestSolr4Spatial, DirectSolrConnectionTest, DistanceUnitsTest, TestDocBasedVersionConstraints, JavabinLoaderTest, TestBM25SimilarityFactory, TestSolrConfigHandler, AutoscalingHistoryHandlerTest, TestZkChroot, TestRawResponseWriter, TestCustomSort, TestSolrJ, QueryEqualityTest, CoreAdminRequestStatusTest, CoreSorterTest, TestXmlQParserPlugin, TriggerIntegrationTest, HdfsWriteToMultipleCollectionsTest, NodeLostTriggerIntegrationTest, TestCoreBackup, SpatialRPTFieldTypeTest, SolrInfoBeanTest, TestDFISimilarityFactory, TestAnalyzeInfixSuggestions, TestDistributedMap, TestSystemCollAutoCreate, TestLeaderElectionWithEmptyReplica, TestDistributedGrouping, HdfsChaosMonkeySafeLeaderTest, TestHttpShardHandlerFactory, ResponseHeaderTest, TestCryptoKeys, RestartWhileUpdatingTest, TestSimpleTrackingShardHandler, CollectionsAPIAsyncDistributedZkTest, TestEmbeddedSolrServerSchemaAPI, TestTlogReplica, TestObjectReleaseTracker, ChaosMonkeySafeLeaderTest, TimeRoutedAliasUpdateProcessorTest, TestRequestForwarding, TestComputePlanAction, TestShortCircuitedRequests, TestReqParamsAPI, JsonLoaderTest, OverriddenZkACLAndCredentialsProvidersTest, TestConfigOverlay, PolyFieldTest, CheckHdfsIndexTest, SimpleCollectionCreateDeleteTest, SoftAutoCommitTest, TestStressUserVersions, TestSchemaSimilarityResource, TestManagedSynonymGraphFilterFactory, CustomCollectionTest, SimplePostToolTest, DOMUtilTest, TestTestInjection, TestStressCloudBlindAtomicUpdates, ZkStateReaderTest, BasicFunctionalityTest, TestReloadAndDeleteDocs, DirectUpdateHandlerOptimizeTest, GraphQueryTest, MetricTriggerTest, TestGenericDistributedQueue, ReplaceNodeNoTargetTest, SolrCloudReportersTest, TestRequestStatusCollectionAPI, ExplicitHLLTest, TestCloudJSONFacetJoinDomain, JSONWriterTest, VMParamsZkACLAndCredentialsProvidersTest, TestCollapseQParserPlugin, ForceLeaderTest, TestQueryUtils, TestFieldCacheReopen, TestNodeLostTrigger, DistribCursorPagingTest, TestMultiWordSynonyms, TestSolrCloudWithDelegationTokens, ChaosMonkeySafeLeaderWithPullReplicasTest, QueryElevationComponentTest, SyncSliceTest, OpenCloseCoreStressTest, TestReplicationHandler] [junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory. [junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestReplicationHandler -Dtests.seed=B3CB0D2BE889AEA6 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.locale=zh-CN -Dtests.timezone=Africa/Bangui -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1 [junit4] ERROR 0.00s J1 | TestReplicationHandler (suite) <<< [junit4] > Throwable #1: java.lang.AssertionError: ObjectTracker found 5 object(s) that were not released!!! [SolrCore, InternalHttpClient, MockDirectoryWrapper, MockDirectoryWrapper, MockDirectoryWrapper] [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.core.SolrCore [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1040) [junit4] > at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) [junit4] > at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) [junit4] > at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.http.impl.client.InternalHttpClient [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:289) [junit4] > at org.apache.solr.client.solrj.impl.HttpClientUtil.createClient(HttpClientUtil.java:298) [junit4] > at org.apache.solr.handler.IndexFetcher.createHttpClient(IndexFetcher.java:248) [junit4] > at org.apache.solr.handler.IndexFetcher.<init>(IndexFetcher.java:290) [junit4] > at org.apache.solr.handler.ReplicationHandler.inform(ReplicationHandler.java:1190) [junit4] > at org.apache.solr.core.SolrResourceLoader.inform(SolrResourceLoader.java:696) [junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:988) [junit4] > at org.apache.solr.core.SolrCore.reload(SolrCore.java:657) [junit4] > at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1302) [junit4] > at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:944) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) [junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) [junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) [junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) [junit4] > at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) [junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [junit4] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [junit4] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) [junit4] > at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:352) [junit4] > at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:730) [junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:955) [junit4] > at org.apache.solr.core.SolrCore.<init>(SolrCore.java:864) [junit4] > at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1047) [junit4] > at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:643) [junit4] > at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) [junit4] > at java.util.concurrent.FutureTask.run(FutureTask.java:266) [junit4] > at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:192) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.lucene.store.MockDirectoryWrapper [junit4] > at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) [junit4] > at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:348) [junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:526) [junit4] > at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:369) [junit4] > at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:420) [junit4] > at org.apache.solr.handler.ReplicationHandler.lambda$setupPolling$12(ReplicationHandler.java:1159) [junit4] > at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [junit4] > at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [junit4] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180) [junit4] > at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > at __randomizedtesting.SeedInfo.seed([B3CB0D2BE889AEA6]:0) [junit4] > at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:303) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] Completed [545/794 (1!)] on J1 in 348.77s, 16 tests, 1 failure, 1 skipped <<< FAILURES! [...truncated 50585 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org