You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/10/19 01:30:25 UTC
[JENKINS] Lucene-Solr-7.x-Windows (64bit/jdk1.8.0_144) - Build #
254 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-Windows/254/
Java: 64bit/jdk1.8.0_144 -XX:+UseCompressedOops -XX:+UseSerialGC
2 tests failed.
FAILED: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.test
Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:62543/ou_vg/lk
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:62543/ou_vg/lk
at __randomizedtesting.SeedInfo.seed([6958EA641D73E635:E10CD5BEB38F8BCD]:0)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:637)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1121)
at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:195)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:315)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:991)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:171)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:525)
... 43 more
FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication
Error Message:
Index: 0, Size: 0
Stack Trace:
java.lang.IndexOutOfBoundsException: Index: 0, Size: 0
at __randomizedtesting.SeedInfo.seed([6958EA641D73E635:7D10B1313E745B2B]:0)
at java.util.ArrayList.rangeCheck(ArrayList.java:653)
at java.util.ArrayList.get(ArrayList.java:429)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication(TestReplicationHandler.java:561)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890)
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 12221 lines...]
[junit4] Suite: org.apache.solr.handler.TestReplicationHandler
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\init-core-data-001
[junit4] 2> 680420 WARN (SUITE-TestReplicationHandler-seed#[6958EA641D73E635]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 680420 INFO (SUITE-TestReplicationHandler-seed#[6958EA641D73E635]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 680424 INFO (SUITE-TestReplicationHandler-seed#[6958EA641D73E635]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None)
[junit4] 2> 680424 INFO (SUITE-TestReplicationHandler-seed#[6958EA641D73E635]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 680425 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testEmptyCommits
[junit4] 2> 680426 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\collection1
[junit4] 2> 680436 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 680436 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6a7a456e{/solr,null,AVAILABLE}
[junit4] 2> 680439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6292927f{HTTP/1.1,[http/1.1]}{127.0.0.1:60335}
[junit4] 2> 680439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server Started @688384ms
[junit4] 2> 680439 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\collection1\data, hostContext=/solr, hostPort=60335}
[junit4] 2> 680440 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 680440 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 680440 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 680440 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 680440 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-19T00:27:47.578Z
[junit4] 2> 680441 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\solr.xml
[junit4] 2> 680446 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 680446 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 680447 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 680524 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680531 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680531 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680536 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\.
[junit4] 2> 680536 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 680536 INFO (coreLoadExecutor-3605-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 680559 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 680568 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 680580 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 680580 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\.\collection1, trusted=true
[junit4] 2> 680581 INFO (coreLoadExecutor-3605-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@6702703f
[junit4] 2> 680581 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 680581 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\.\collection1\data\]
[junit4] 2> 680582 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 680643 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 680643 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 680644 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=34.6826171875, floorSegmentMB=0.3701171875, forceMergeDeletesPctAllowed=14.492466086940741, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21201772631441154
[junit4] 2> 680644 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3924c77f[collection1] main]
[junit4] 2> 680644 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-001\collection1\conf
[junit4] 2> 680645 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 680645 INFO (coreLoadExecutor-3605-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 680645 INFO (searcherExecutor-3606-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3924c77f[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 680649 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\collection1
[junit4] 2> 680656 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 680657 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@cd38f8f{/solr,null,AVAILABLE}
[junit4] 2> 680657 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@52bb327b{HTTP/1.1,[http/1.1]}{127.0.0.1:60338}
[junit4] 2> 680658 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server Started @688603ms
[junit4] 2> 680658 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\collection1\data, hostContext=/solr, hostPort=60338}
[junit4] 2> 680658 ERROR (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 680659 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 680659 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 680659 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 680659 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-19T00:27:47.797Z
[junit4] 2> 680659 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\solr.xml
[junit4] 2> 680665 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 680665 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 680666 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 680729 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680736 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680736 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 680740 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\.
[junit4] 2> 680740 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 680741 INFO (coreLoadExecutor-3615-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 680764 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 680770 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 680772 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 680772 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\.\collection1, trusted=true
[junit4] 2> 680773 INFO (coreLoadExecutor-3615-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@6702703f
[junit4] 2> 680773 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 680773 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\.\collection1\data\]
[junit4] 2> 680774 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 680848 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 680848 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 680848 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=34.6826171875, floorSegmentMB=0.3701171875, forceMergeDeletesPctAllowed=14.492466086940741, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21201772631441154
[junit4] 2> 680848 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5d03951d[collection1] main]
[junit4] 2> 680849 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-002\collection1\conf
[junit4] 2> 680851 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 680851 INFO (coreLoadExecutor-3615-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 680852 INFO (searcherExecutor-3616-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5d03951d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 680854 INFO (qtp140005323-8955) [ 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> 680855 INFO (qtp140005323-8953) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1]} 0 0
[junit4] 2> 680855 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 680855 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@37881047 commitCommandVersion:0
[junit4] 2> 680857 INFO (qtp140005323-8952) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5063eb78[collection1] main]
[junit4] 2> 680858 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 680858 INFO (searcherExecutor-3606-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5063eb78[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1)))}
[junit4] 2> 680858 INFO (qtp140005323-8952) [ 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> 680862 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 680865 INFO (qtp140005323-8951) [ 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> 680865 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 680865 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1508372867993
[junit4] 2> 680865 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1
[junit4] 2> 680865 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0
[junit4] 2> 680865 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 680876 INFO (qtp140005323-8951) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=10
[junit4] 2> 680876 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 4
[junit4] 2> 680877 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=74.0927734375, floorSegmentMB=1.5576171875, forceMergeDeletesPctAllowed=11.257889111373718, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7677476506518651
[junit4] 2> 680878 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 680878 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@3afd7eb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6bd08501)
[junit4] 2> 680878 INFO (qtp140005323-8950) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 680879 INFO (qtp140005323-8950) [ 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> 680880 INFO (qtp140005323-8949) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 680881 INFO (qtp140005323-8948) [ 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> 680882 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1913) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@3afd7eb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6bd08501)
[junit4] 2> 680883 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 680884 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 680884 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@298fc623[collection1] main]
[junit4] 2> 680885 INFO (searcherExecutor-3616-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@298fc623[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1)))}
[junit4] 2> 680885 INFO (qtp1916272062-8968) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:60335/solr/collection1/replication&command=fetchindex} status=0 QTime=23
[junit4] 2> 680888 INFO (qtp1916272062-8969) [ 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=1
[junit4] 2> 680889 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 680889 INFO (qtp140005323-8948) [ 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> 680890 INFO (qtp140005323-8948) [ 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> 680891 INFO (qtp140005323-8946) [ 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> 680891 INFO (qtp1916272062-8970) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getDetails&qt=/replication&wt=javabin&version=2&command=details} status=0 QTime=1
[junit4] 2> 680891 INFO (qtp140005323-8955) [ 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> 680891 INFO (qtp1916272062-8971) [ 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> 680891 INFO (qtp140005323-8955) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 680891 INFO (qtp140005323-8955) [ x:collection1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 680891 INFO (qtp140005323-8955) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 680891 INFO (qtp140005323-8955) [ 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> 680893 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 680894 INFO (qtp140005323-8946) [ 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> 680894 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2
[junit4] 2> 680894 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1508372867993
[junit4] 2> 680894 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 680894 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1508372867993
[junit4] 2> 680894 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master.
[junit4] 2> 680894 INFO (qtp1916272062-8971) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:60335/solr/collection1/replication&command=fetchindex} status=0 QTime=1
[junit4] 2> 680897 INFO (qtp140005323-8946) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2]} 0 1
[junit4] 2> 680897 INFO (qtp140005323-8946) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 680897 INFO (qtp140005323-8946) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@37881047 commitCommandVersion:0
[junit4] 2> 680898 INFO (qtp140005323-8946) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5ac19bdc[collection1] main]
[junit4] 2> 680898 INFO (qtp140005323-8946) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 680899 INFO (searcherExecutor-3606-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@5ac19bdc[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1) Uninverting(_1(7.2.0):c1)))}
[junit4] 2> 680899 INFO (qtp140005323-8946) [ 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> 680901 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 680902 INFO (qtp140005323-8951) [ 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> 680902 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 3
[junit4] 2> 680902 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1508372868035
[junit4] 2> 680902 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2
[junit4] 2> 680902 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1508372867993
[junit4] 2> 680902 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 680903 INFO (qtp140005323-8951) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 680903 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 7
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=74.0927734375, floorSegmentMB=1.5576171875, forceMergeDeletesPctAllowed=11.257889111373718, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7677476506518651
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@2cad94ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56c770c)
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfe because it already exists
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 680904 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfs because it already exists
[junit4] 2> 680904 INFO (qtp140005323-8949) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 680906 INFO (qtp140005323-8949) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=3&qt=/replication&file=_1.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 680906 INFO (qtp140005323-8957) [ 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> 680907 INFO (qtp140005323-8948) [ 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> 680908 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=1994) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@2cad94ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56c770c)
[junit4] 2> 680909 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 680910 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 680910 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@156d2315[collection1] main]
[junit4] 2> 680911 INFO (searcherExecutor-3616-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@156d2315[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1) Uninverting(_1(7.2.0):c1)))}
[junit4] 2> 680911 INFO (qtp1916272062-8973) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:60335/solr/collection1/replication&command=fetchindex} status=0 QTime=11
[junit4] 2> 680912 INFO (qtp1916272062-8966) [ 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> 680912 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 680913 INFO (qtp140005323-8953) [ 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> 680913 INFO (qtp140005323-8953) [ 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> 680914 INFO (qtp140005323-8955) [ 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> 680914 INFO (qtp1916272062-8968) [ 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> 680914 INFO (qtp140005323-8952) [ 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> 680915 INFO (qtp1916272062-8969) [ 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> 680915 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3]} 0 0
[junit4] 2> 680915 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 680915 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@37881047 commitCommandVersion:0
[junit4] 2> 680916 INFO (qtp140005323-8952) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@21c7a6bd[collection1] realtime]
[junit4] 2> 680917 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 680917 INFO (qtp140005323-8952) [ 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> 680918 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 680919 INFO (qtp140005323-8955) [ 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> 680919 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 4
[junit4] 2> 680919 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1508372868053
[junit4] 2> 680919 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 3
[junit4] 2> 680919 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1508372868035
[junit4] 2> 680919 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 680920 INFO (qtp140005323-8950) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 680920 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 10
[junit4] 2> 680921 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=74.0927734375, floorSegmentMB=1.5576171875, forceMergeDeletesPctAllowed=11.257889111373718, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7677476506518651
[junit4] 2> 680922 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 680922 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 680922 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 681923 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 681923 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 682932 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 682933 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 683934 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 683934 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 684934 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 684934 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 685935 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 685935 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 686936 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 686936 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 687937 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 687937 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 688937 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 688937 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 689938 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 689938 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 690938 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Found unused file: segments_2
[junit4] 2> 690938 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Sleeping for 1000ms to wait for unused lucene index files to be delete-able
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher IndexFetcher slept for 11000ms for unused lucene index files to be delete-able
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@407309aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@778efcde)
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfe because it already exists
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfs because it already exists
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.cfs because it already exists
[junit4] 2> 691939 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.cfe because it already exists
[junit4] 2> 691940 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists
[junit4] 2> 691942 INFO (qtp140005323-8951) [ 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> 691944 INFO (qtp140005323-8949) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 691947 INFO (qtp140005323-8957) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=4&qt=/replication&file=_2.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 691949 INFO (qtp140005323-8948) [ 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> 691949 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=2075) : 11 secs (188 bytes/sec) to MockDirectoryWrapper(RAMDirectory@407309aa lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@778efcde)
[junit4] 2> 691952 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 691952 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 691953 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@36f76292[collection1] main]
[junit4] 2> 691955 INFO (searcherExecutor-3616-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@36f76292[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1) Uninverting(_1(7.2.0):c1) Uninverting(_2(7.2.0):c1)))}
[junit4] 2> 691955 INFO (qtp1916272062-8969) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:60335/solr/collection1/replication&command=fetchindex} status=0 QTime=11037
[junit4] 2> 691958 INFO (qtp140005323-8953) [ 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> 691959 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs
[junit4] 2> 691960 INFO (qtp1916272062-8972) [ 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> 691960 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 1 docs
[junit4] 2> 691961 INFO (qtp140005323-8946) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4]} 0 0
[junit4] 2> 691961 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 691961 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@37881047 commitCommandVersion:0
[junit4] 2> 691962 INFO (qtp140005323-8952) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@33e0fb5b[collection1] main]
[junit4] 2> 691963 INFO (qtp140005323-8952) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 691964 INFO (searcherExecutor-3606-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@33e0fb5b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1) Uninverting(_1(7.2.0):c1) Uninverting(_2(7.2.0):c1) Uninverting(_3(7.2.0):c1)))}
[junit4] 2> 691964 INFO (qtp140005323-8952) [ 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> 691965 WARN (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher 'masterUrl' must be specified without the /replication suffix
[junit4] 2> 691967 INFO (qtp140005323-8955) [ 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> 691967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 5
[junit4] 2> 691967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1508372879099
[junit4] 2> 691967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 4
[junit4] 2> 691967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1508372868053
[junit4] 2> 691967 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process
[junit4] 2> 691968 INFO (qtp140005323-8950) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&wt=javabin&version=2&command=filelist} status=0 QTime=0
[junit4] 2> 691968 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 13
[junit4] 2> 691969 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=74.0927734375, floorSegmentMB=1.5576171875, forceMergeDeletesPctAllowed=11.257889111373718, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7677476506518651
[junit4] 2> 691969 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@3b9dd2ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@722f132a)
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfe because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.si because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _0.cfs because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.cfs because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.cfe because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _1.si because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.si because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.cfe because it already exists
[junit4] 2> 691970 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Skipping download for _2.cfs because it already exists
[junit4] 2> 691970 INFO (qtp140005323-8951) [ 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> 691971 INFO (qtp140005323-8949) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 691972 INFO (qtp140005323-8957) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=5&qt=/replication&file=_3.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
[junit4] 2> 691972 INFO (qtp140005323-8948) [ 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> 691973 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=2156) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@3b9dd2ee lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@722f132a)
[junit4] 2> 691974 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=47, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 691975 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 691975 INFO (explicit-fetchindex-cmd) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4302207b[collection1] main]
[junit4] 2> 691976 INFO (searcherExecutor-3616-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4302207b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.2.0):c1) Uninverting(_1(7.2.0):c1) Uninverting(_2(7.2.0):c1) Uninverting(_3(7.2.0):c1)))}
[junit4] 2> 691977 INFO (qtp1916272062-8971) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={wait=true&masterUrl=http://127.0.0.1:60335/solr/collection1/replication&command=fetchindex} status=0 QTime=11
[junit4] 2> 691977 INFO (qtp140005323-8953) [ 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> 691978 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs
[junit4] 2> 691978 INFO (qtp1916272062-8973) [ 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> 691979 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 4 docs
[junit4] 2> 691979 INFO (qtp140005323-8946) [ 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> 691979 INFO (qtp140005323-8952) [ 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> 691980 INFO (qtp140005323-8955) [ 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> 691981 INFO (qtp1916272062-8966) [ 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> 691981 INFO (qtp140005323-8950) [ 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> 691981 INFO (qtp1916272062-8968) [ 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> 691982 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testEmptyCommits
[junit4] 2> 691982 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@6292927f{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 691982 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=622476802
[junit4] 2> 691983 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 691983 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6599c31c: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@455328ce
[junit4] 2> 691986 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 691986 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5d2c267b: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@16d758e5
[junit4] 2> 691988 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 691988 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4cce7ea: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@8b4ff82
[junit4] 2> 691989 INFO (coreCloseExecutor-3625-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3e9579ab
[junit4] 2> 691989 INFO (coreCloseExecutor-3625-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1049983403
[junit4] 2> 691989 INFO (coreCloseExecutor-3625-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33e9f45f: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@5a484d29
[junit4] 2> 691995 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6a7a456e{/solr,null,UNAVAILABLE}
[junit4] 2> 691997 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@52bb327b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 691997 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=510536769
[junit4] 2> 691998 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 691998 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3109401b: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@5e77423a
[junit4] 2> 692002 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 692002 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@52503aa8: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@16d758e5
[junit4] 2> 692005 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 692005 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4a2de034: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@8b4ff82
[junit4] 2> 692006 INFO (coreCloseExecutor-3627-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3f1ecc6b
[junit4] 2> 692006 INFO (coreCloseExecutor-3627-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1058983019
[junit4] 2> 692006 INFO (coreCloseExecutor-3627-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6e1ad872: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@1784256b
[junit4] 2> 692013 INFO (TEST-TestReplicationHandler.testEmptyCommits-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@cd38f8f{/solr,null,UNAVAILABLE}
[junit4] 2> 692015 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestIllegalFilePaths
[junit4] 2> 692016 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\collection1
[junit4] 2> 692025 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 692025 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6bd7478{/solr,null,AVAILABLE}
[junit4] 2> 692026 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@70318101{HTTP/1.1,[http/1.1]}{127.0.0.1:60391}
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server Started @699971ms
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\collection1\data, hostContext=/solr, hostPort=60391}
[junit4] 2> 692027 ERROR (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 692027 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-19T00:27:59.165Z
[junit4] 2> 692028 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\solr.xml
[junit4] 2> 692034 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 692034 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 692034 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 692103 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692108 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692108 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692112 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\.
[junit4] 2> 692112 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 692113 INFO (coreLoadExecutor-3634-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 692134 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 692138 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 692141 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 692141 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\.\collection1, trusted=true
[junit4] 2> 692141 INFO (coreLoadExecutor-3634-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@6702703f
[junit4] 2> 692141 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
[junit4] 2> 692141 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\.\collection1\data\]
[junit4] 2> 692143 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=20, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 692196 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 692196 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 692197 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=37, maxMergedSegmentMB=34.6826171875, floorSegmentMB=0.3701171875, forceMergeDeletesPctAllowed=14.492466086940741, segmentsPerTier=16.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.21201772631441154
[junit4] 2> 692197 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@21af35e4[collection1] main]
[junit4] 2> 692197 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-003\collection1\conf
[junit4] 2> 692198 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl
[junit4] 2> 692198 INFO (coreLoadExecutor-3634-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 692198 INFO (searcherExecutor-3635-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@21af35e4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 692202 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-004\collection1
[junit4] 2> 692210 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531
[junit4] 2> 692210 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1a0e5ae{/solr,null,AVAILABLE}
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@54139b9e{HTTP/1.1,[http/1.1]}{127.0.0.1:60394}
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.e.j.s.Server Started @700156ms
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-004\collection1\data, hostContext=/solr, hostPort=60394}
[junit4] 2> 692211 ERROR (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null
[junit4] 2> 692211 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-10-19T00:27:59.349Z
[junit4] 2> 692212 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-004\solr.xml
[junit4] 2> 692219 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
[junit4] 2> 692219 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
[junit4] 2> 692220 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 692287 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692294 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692294 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@6702703f
[junit4] 2> 692298 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J0\temp\solr.handler.TestReplicationHandler_6958EA641D73E635-001\solr-instance-004\.
[junit4] 2> 692298 INFO (TEST-TestReplicationHandler.doTestIllegalFilePaths-seed#[6958EA641D73E635]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
[junit4] 2> 692299 INFO (coreLoadExecutor-3644-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 692332 INFO (coreLoadExecutor-3644-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0
[junit4] 2> 692337 INFO (coreLoadExecutor-3644-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 692340 INFO (coreLoadExecutor-3644-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id
[junit4] 2> 692340 INFO (coreLoadExecutor-3644-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creati
[...truncated too long message...]
e&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=600025
[junit4] 2> 1550037 ERROR (TEST-FullSolrCloudDistribCmdsTest.test-seed#[6958EA641D73E635]) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes
[junit4] 2> 1550038 INFO (TEST-FullSolrCloudDistribCmdsTest.test-seed#[6958EA641D73E635]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:62536 62536
[junit4] 2> 1550038 INFO (Thread-2154) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:62536 62536
[junit4] 2> 1550039 WARN (Thread-2154) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/clusterstate.json
[junit4] 2> 2 /solr/clusterprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 2 /solr/live_nodes
[junit4] 2> 2 /solr/collections
[junit4] 2>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=FullSolrCloudDistribCmdsTest -Dtests.method=test -Dtests.seed=6958EA641D73E635 -Dtests.slow=true -Dtests.locale=da -Dtests.timezone=Africa/Mbabane -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 601s J1 | FullSolrCloudDistribCmdsTest.test <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:62543/ou_vg/lk
[junit4] > at __randomizedtesting.SeedInfo.seed([6958EA641D73E635:E10CD5BEB38F8BCD]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:637)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:253)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:242)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1121)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178)
[junit4] > at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:195)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createServers(AbstractFullDistribZkTestBase.java:315)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:991)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:968)
[junit4] > at java.lang.Thread.run(Thread.java:748)
[junit4] > Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] > at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:171)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:141)
[junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
[junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
[junit4] > at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
[junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
[junit4] > at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
[junit4] > at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
[junit4] > at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
[junit4] > at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
[junit4] > at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
[junit4] > at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:111)
[junit4] > at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:525)
[junit4] > ... 43 more
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-7.x-Windows\solr\build\solr-core\test\J1\temp\solr.cloud.FullSolrCloudDistribCmdsTest_6958EA641D73E635-001
[junit4] 2> Oct 19, 2017 12:42:17 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene70): {}, docValues:{}, maxPointsInLeafNode=1612, maxMBSortInHeap=6.1382527936009765, sim=RandomSimilarity(queryNorm=true): {}, locale=da, timezone=Africa/Mbabane
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 1.8.0_144 (64-bit)/cpus=3,threads=1,free=147066488,total=344903680
[junit4] 2> NOTE: All tests run in this JVM: [TestSearchPerf, PluginInfoTest, TestComplexPhraseQParserPlugin, SolrPluginUtilsTest, DeleteLastCustomShardedReplicaTest, AnalyticsMergeStrategyTest, TestNumericRangeQuery32, EchoParamsTest, TestLMJelinekMercerSimilarityFactory, DistributedExpandComponentTest, TestJettySolrRunner, TestHdfsBackupRestoreCore, PeerSyncTest, ZkSolrClientTest, TestSchemaVersionResource, TestAnalyzeInfixSuggestions, UpdateRequestProcessorFactoryTest, TestExpandComponent, SolrIndexSplitterTest, UpdateParamsTest, MetricUtilsTest, SolrCoreTest, TestMergePolicyConfig, QueryEqualityTest, TriggerIntegrationTest, TestFieldCacheReopen, RuleEngineTest, TestDocumentBuilder, TestFastOutputStream, DataDrivenBlockJoinTest, ZkFailoverTest, TestCloudPseudoReturnFields, DeleteReplicaTest, TestLRUStatsCache, CloneFieldUpdateProcessorFactoryTest, DistributedFacetPivotWhiteBoxTest, DocValuesNotIndexedTest, SmileWriterTest, TestObjectReleaseTracker, LeaderFailoverAfterPartitionTest, ZkNodePropsTest, TestLegacyTerms, TestAuthorizationFramework, TermsComponentTest, DistributedMLTComponentTest, QueryElevationComponentTest, ComputePlanActionTest, TestDocSet, BadComponentTest, DistribDocExpirationUpdateProcessorTest, SimpleMLTQParserTest, TestReloadDeadlock, TestSystemCollAutoCreate, AddSchemaFieldsUpdateProcessorFactoryTest, TestSQLHandler, TestReload, TestManagedSynonymFilterFactory, TestSolrJ, FieldMutatingUpdateProcessorTest, TestStressReorder, HdfsWriteToMultipleCollectionsTest, TestNumericTokenStream, TestPerFieldSimilarity, OpenExchangeRatesOrgProviderTest, TestSolrDeletionPolicy1, TestMacros, FileBasedSpellCheckerTest, ExitableDirectoryReaderTest, TestGeoJSONResponseWriter, TestManagedSchemaThreadSafety, TestNumericTerms32, ConjunctionSolrSpellCheckerTest, TestReqParamsAPI, SolrCLIZkUtilsTest, MigrateRouteKeyTest, TestSolrCloudWithDelegationTokens, TestInPlaceUpdatesDistrib, TestDocTermOrds, ActionThrottleTest, DOMUtilTest, MoreLikeThisHandlerTest, TestPartialUpdateDeduplication, TestFieldSortValues, AutoAddReplicasPlanActionTest, AliasIntegrationTest, HdfsSyncSliceTest, TestSortByMinMaxFunction, TestFaceting, SolrSlf4jReporterTest, TestReplicaProperties, TestJsonRequest, TestSolrCloudSnapshots, TestPayloadScoreQParserPlugin, TestTrie, AnalysisAfterCoreReloadTest, TestFieldCacheWithThreads, TestSchemaManager, SolrJmxReporterCloudTest, TestHashPartitioner, TestHighFrequencyDictionaryFactory, LukeRequestHandlerTest, TestSubQueryTransformerCrossCore, BlockJoinFacetSimpleTest, TestDeleteCollectionOnDownNodes, TestCrossCoreJoin, NodeMutatorTest, MoveReplicaHDFSFailoverTest, BitVectorTest, TestBadConfig, TestSolrIndexConfig, TestExactSharedStatsCache, RequestLoggingTest, CustomCollectionTest, TestDownShardTolerantSearch, TestCloudNestedDocsSort, BasicAuthStandaloneTest, HLLUtilTest, TemplateUpdateProcessorTest, ConcurrentDeleteAndCreateCollectionTest, TestCloudJSONFacetJoinDomain, PingRequestHandlerTest, TestFieldCacheSortRandom, BlockDirectoryTest, TestLocalFSCloudBackupRestore, CacheHeaderTest, TestConfigSetProperties, TestSimpleQParserPlugin, HdfsChaosMonkeySafeLeaderTest, SolrShardReporterTest, TestSizeLimitedDistributedMap, TestNRTOpen, TestSolrFieldCacheBean, FullSolrCloudDistribCmdsTest]
[junit4] Completed [322/743 (2!)] on J1 in 602.22s, 1 test, 1 error <<< FAILURES!
[...truncated 48680 lines...]