You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2019/11/03 17:04:35 UTC

[JENKINS] Lucene-Solr-8.x-Linux (64bit/jdk-13) - Build # 1440 - Unstable!

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/1440/
Java: 64bit/jdk-13 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
FAILED:  org.apache.solr.cloud.TestTlogReplica.testRecovery

Error Message:
Error from server at https://127.0.0.1:40849/solr: Underlying core creation failed while creating collection: tlog_replica_test_recovery

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:40849/solr: Underlying core creation failed while creating collection: tlog_replica_test_recovery
	at __randomizedtesting.SeedInfo.seed([8AC39BFFB0A0AA61:4B33E2539DF060C6]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:665)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
	at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:368)
	at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:296)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1127)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:896)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:828)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:211)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:228)
	at org.apache.solr.cloud.TestTlogReplica.createAndWaitForCollection(TestTlogReplica.java:753)
	at org.apache.solr.cloud.TestTlogReplica.testRecovery(TestTlogReplica.java:535)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:567)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
	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:947)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
	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 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.base/java.lang.Thread.run(Thread.java:830)




Build Log:
[...truncated 13852 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestTlogReplica
   [junit4]   2> 416465 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/data-dir-43-001
   [junit4]   2> 416465 WARN  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
   [junit4]   2> 416465 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 416466 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
   [junit4]   2> 416466 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 416467 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001
   [junit4]   2> 416467 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 416467 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 416467 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 416567 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer start zk server on port:38927
   [junit4]   2> 416567 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:38927
   [junit4]   2> 416567 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38927
   [junit4]   2> 416567 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38927
   [junit4]   2> 416569 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416572 INFO  (zkConnectionManagerCallback-2924-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416572 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416574 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416575 INFO  (zkConnectionManagerCallback-2926-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416575 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416576 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416577 INFO  (zkConnectionManagerCallback-2928-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416577 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416685 WARN  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 416685 WARN  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.Server jetty-9.4.19.v20190610; built: 2019-06-10T16:30:51.723Z; git: afcf563148970e98786327af5e07c261fda175d3; jvm 13+33
   [junit4]   2> 416685 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.Server jetty-9.4.19.v20190610; built: 2019-06-10T16:30:51.723Z; git: afcf563148970e98786327af5e07c261fda175d3; jvm 13+33
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@129bfcf5{/solr,null,AVAILABLE}
   [junit4]   2> 416686 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22aef69c{/solr,null,AVAILABLE}
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.AbstractConnector Started ServerConnector@1965eddc{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:46815}
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.e.j.s.Server Started @416724ms
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.AbstractConnector Started ServerConnector@5c864fd8{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:40849}
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46815}
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.e.j.s.Server Started @416724ms
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40849}
   [junit4]   2> 416687 ERROR (jetty-launcher-2929-thread-1) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 416687 ERROR (jetty-launcher-2929-thread-2) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.4.0
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.4.0
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-11-03T16:14:17.260487Z
   [junit4]   2> 416687 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2019-11-03T16:14:17.260487Z
   [junit4]   2> 416688 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416688 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416689 INFO  (zkConnectionManagerCallback-2932-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416689 INFO  (zkConnectionManagerCallback-2933-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416689 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416689 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416689 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 416689 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 416850 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 416851 WARN  (jetty-launcher-2929-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@240ff19b[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416851 WARN  (jetty-launcher-2929-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@240ff19b[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416853 WARN  (jetty-launcher-2929-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@44e06f1c[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416853 WARN  (jetty-launcher-2929-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@44e06f1c[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416854 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38927/solr
   [junit4]   2> 416855 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416856 INFO  (zkConnectionManagerCallback-2940-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416856 INFO  (jetty-launcher-2929-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416923 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 416924 WARN  (jetty-launcher-2929-thread-2) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@273ceb26[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416924 WARN  (jetty-launcher-2929-thread-2) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@273ceb26[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416925 WARN  (jetty-launcher-2929-thread-2) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@51bef103[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416925 WARN  (jetty-launcher-2929-thread-2) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@51bef103[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 416926 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38927/solr
   [junit4]   2> 416927 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416927 INFO  (zkConnectionManagerCallback-2947-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416927 INFO  (jetty-launcher-2929-thread-2) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 416993 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 416994 INFO  (zkConnectionManagerCallback-2949-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 416994 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 417029 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46815_solr
   [junit4]   2> 417029 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.Overseer Overseer (id=72420335715942407-127.0.0.1:46815_solr-n_0000000000) starting
   [junit4]   2> 417031 INFO  (OverseerStateUpdate-72420335715942407-127.0.0.1:46815_solr-n_0000000000) [n:127.0.0.1:46815_solr     ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46815_solr
   [junit4]   2> 417031 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46815_solr
   [junit4]   2> 417033 INFO  (zkCallback-2948-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 417040 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 417051 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46815.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417057 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46815.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417057 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46815.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417057 INFO  (jetty-launcher-2929-thread-1) [n:127.0.0.1:46815_solr     ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node1/.
   [junit4]   2> 417093 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 417094 INFO  (zkConnectionManagerCallback-2955-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 417094 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 417099 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 417102 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.ZkController Publish node=127.0.0.1:40849_solr as DOWN
   [junit4]   2> 417102 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 417102 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40849_solr
   [junit4]   2> 417103 INFO  (zkCallback-2948-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 417103 INFO  (zkCallback-2954-thread-1) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 417110 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 417124 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40849.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417129 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40849.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417129 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40849.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 417130 INFO  (jetty-launcher-2929-thread-2) [n:127.0.0.1:40849_solr     ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node2/.
   [junit4]   2> 417144 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
   [junit4]   2> 417145 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 417146 INFO  (zkConnectionManagerCallback-2964-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 417146 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 417147 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
   [junit4]   2> 417147 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38927/solr ready
   [junit4]   2> 417149 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.TestTlogReplica Using legacyCloud?: false
   [junit4]   2> 417161 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr     ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 417162 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 417172 INFO  (TEST-TestTlogReplica.testAddDocs-seed#[8AC39BFFB0A0AA61]) [     ] o.a.s.SolrTestCaseJ4 ###Starting testAddDocs
   [junit4]   2> 417174 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr     ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_add_docs&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=3&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 417175 INFO  (OverseerThreadFactory-3200-thread-1-processing-n:127.0.0.1:46815_solr) [n:127.0.0.1:46815_solr     ] o.a.s.c.a.c.CreateCollectionCmd Create collection tlog_replica_test_add_docs
   [junit4]   2> 417277 WARN  (OverseerThreadFactory-3200-thread-1-processing-n:127.0.0.1:46815_solr) [n:127.0.0.1:46815_solr     ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection tlog_replica_test_add_docs is higher than the number of Solr instances currently live or live and part of your createNodeSet(2). It's unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 417280 INFO  (OverseerStateUpdate-72420335715942407-127.0.0.1:46815_solr-n_0000000000) [n:127.0.0.1:46815_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"tlog_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"tlog_replica_test_add_docs_shard1_replica_t1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46815/solr",
   [junit4]   2>   "type":"TLOG",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 417282 INFO  (OverseerStateUpdate-72420335715942407-127.0.0.1:46815_solr-n_0000000000) [n:127.0.0.1:46815_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"tlog_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"tlog_replica_test_add_docs_shard1_replica_t2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:40849/solr",
   [junit4]   2>   "type":"TLOG",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 417283 INFO  (OverseerStateUpdate-72420335715942407-127.0.0.1:46815_solr-n_0000000000) [n:127.0.0.1:46815_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"tlog_replica_test_add_docs",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"tlog_replica_test_add_docs_shard1_replica_t4",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"https://127.0.0.1:46815/solr",
   [junit4]   2>   "type":"TLOG",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 417490 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr    x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 417493 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr    x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 417493 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr    x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 417496 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr    x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t4&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG
   [junit4]   2> 418496 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.4.0
   [junit4]   2> 418505 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shard1_replica_t2] Schema name=minimal
   [junit4]   2> 418505 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.4.0
   [junit4]   2> 418505 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.4.0
   [junit4]   2> 418506 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 418506 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_add_docs_shard1_replica_t2' using configuration from collection tlog_replica_test_add_docs, trusted=true
   [junit4]   2> 418507 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40849.solr.core.tlog_replica_test_add_docs.shard1.replica_t2' (registry 'solr.core.tlog_replica_test_add_docs.shard1.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 418507 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node2/tlog_replica_test_add_docs_shard1_replica_t2], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node2/./tlog_replica_test_add_docs_shard1_replica_t2/data/]
   [junit4]   2> 418510 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shard1_replica_t4] Schema name=minimal
   [junit4]   2> 418510 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shard1_replica_t1] Schema name=minimal
   [junit4]   2> 418511 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 418511 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_add_docs_shard1_replica_t1' using configuration from collection tlog_replica_test_add_docs, trusted=true
   [junit4]   2> 418511 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 418511 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_add_docs_shard1_replica_t4' using configuration from collection tlog_replica_test_add_docs, trusted=true
   [junit4]   2> 418512 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46815.solr.core.tlog_replica_test_add_docs.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_add_docs.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 418512 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46815.solr.core.tlog_replica_test_add_docs.shard1.replica_t4' (registry 'solr.core.tlog_replica_test_add_docs.shard1.replica_t4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@31805a58
   [junit4]   2> 418512 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node1/tlog_replica_test_add_docs_shard1_replica_t1], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node1/./tlog_replica_test_add_docs_shard1_replica_t1/data/]
   [junit4]   2> 418512 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1_replica_t4] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node1/tlog_replica_test_add_docs_shard1_replica_t4], dataDir=[/home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001/tempDir-001/node1/./tlog_replica_test_add_docs_shard1_replica_t4/data/]
   [junit4]   2> 418535 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 418535 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 418536 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 418536 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 418537 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@753ee78b[tlog_replica_test_add_docs_shard1_replica_t2] main]
   [junit4]   2> 418537 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 418537 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 418537 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 418538 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 418538 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 418538 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1649197878199975936
   [junit4]   2> 418538 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 418538 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 418539 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@16824fc9[tlog_replica_test_add_docs_shard1_replica_t4] main]
   [junit4]   2> 418540 INFO  (searcherExecutor-3209-thread-1-processing-n:127.0.0.1:40849_solr x:tlog_replica_test_add_docs_shard1_replica_t2 c:tlog_replica_test_add_docs s:shard1 r:core_node5) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t2] Registered new searcher Searcher@753ee78b[tlog_replica_test_add_docs_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 418540 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 418541 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 418541 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 418541 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1649197878203121664
   [junit4]   2> 418541 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node5=0}, version=0}
   [junit4]   2> 418542 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_add_docs/leaders/shard1
   [junit4]   2> 418543 INFO  (searcherExecutor-3211-thread-1-processing-n:127.0.0.1:46815_solr x:tlog_replica_test_add_docs_shard1_replica_t4 c:tlog_replica_test_add_docs s:shard1 r:core_node6) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t4] Registered new searcher Searcher@16824fc9[tlog_replica_test_add_docs_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 418544 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=3 found=1 timeoutin=9999ms
   [junit4]   2> 418544 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node6=0, core_node5=0}, version=1}
   [junit4]   2> 418544 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_add_docs/leaders/shard1
   [junit4]   2> 418546 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 418546 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 418547 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 418547 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 418547 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@7d290beb[tlog_replica_test_add_docs_shard1_replica_t1] main]
   [junit4]   2> 418548 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
   [junit4]   2> 418548 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
   [junit4]   2> 418549 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 418549 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1649197878211510272
   [junit4]   2> 418551 INFO  (searcherExecutor-3210-thread-1-processing-n:127.0.0.1:46815_solr x:tlog_replica_test_add_docs_shard1_replica_t1 c:tlog_replica_test_add_docs s:shard1 r:core_node3) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] Registered new searcher Searcher@7d290beb[tlog_replica_test_add_docs_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 418551 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node6=0, core_node3=0, core_node5=0}, version=2}
   [junit4]   2> 418551 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_add_docs/leaders/shard1
   [junit4]   2> 419045 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 419045 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 419045 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/
   [junit4]   2> 419045 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_add_docs_shard1_replica_t2 url=https://127.0.0.1:40849/solr START replicas=[https://127.0.0.1:46815/solr/tlog_replica_test_add_docs_shard1_replica_t1/, https://127.0.0.1:46815/solr/tlog_replica_test_add_docs_shard1_replica_t4/] nUpdates=100
   [junit4]   2> 419045 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_add_docs_shard1_replica_t2 url=https://127.0.0.1:40849/solr DONE.  We have no versions.  sync failed.
   [junit4]   2> 419051 INFO  (qtp1453265732-9846) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t4]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 419062 INFO  (qtp1453265732-9920) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 419062 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 419062 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 419062 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t2 stopping background replication from leader
   [junit4]   2> 419062 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/tlog_replica_test_add_docs/leaders/shard1/leader after winning as /collections/tlog_replica_test_add_docs/leader_elect/shard1/election/72420335715942408-core_node5-n_0000000000
   [junit4]   2> 419064 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/ shard1
   [junit4]   2> 419165 INFO  (zkCallback-2954-thread-1) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419166 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 419168 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=1678
   [junit4]   2> 419267 INFO  (zkCallback-2954-thread-1) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419268 INFO  (zkCallback-2954-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419546 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t4 starting background replication from leader
   [junit4]   2> 419546 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:01
   [junit4]   2> 419548 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
   [junit4]   2> 419548 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 419549 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/
   [junit4]   2> 419549 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t4&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2053
   [junit4]   2> 419552 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t1 starting background replication from leader
   [junit4]   2> 419552 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:01
   [junit4]   2> 419552 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
   [junit4]   2> 419553 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.s.SolrIndexSearcher Opening [Searcher@13fc1d38[tlog_replica_test_add_docs_shard1_replica_t4] main]
   [junit4]   2> 419553 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
   [junit4]   2> 419553 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 419553 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Updated masterUrl to https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/
   [junit4]   2> 419554 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Master's generation: 1
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Master's version: 0
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher New index in Master. Deleting mine...
   [junit4]   2> 419554 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.s.SolrIndexSearcher Opening [Searcher@32004b15[tlog_replica_test_add_docs_shard1_replica_t1] main]
   [junit4]   2> 419554 INFO  (searcherExecutor-3211-thread-1) [     ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t4] Registered new searcher Searcher@13fc1d38[tlog_replica_test_add_docs_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 419554 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=2061
   [junit4]   2> 419555 INFO  (searcherExecutor-3210-thread-1) [     ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] Registered new searcher Searcher@32004b15[tlog_replica_test_add_docs_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 419556 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr     ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
   [junit4]   2> 419655 INFO  (zkCallback-2954-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419655 INFO  (zkCallback-2954-thread-1) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419655 INFO  (zkCallback-2948-thread-1) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419655 INFO  (zkCallback-2948-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
   [junit4]   2> 419656 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_add_docs&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=3&wt=javabin&version=2} status=0 QTime=2482
   [junit4]   2> 419656 INFO  (TEST-TestTlogReplica.testAddDocs-seed#[8AC39BFFB0A0AA61]) [     ] o.a.s.c.SolrCloudTestCase waitForState (tlog_replica_test_add_docs): Expected collection to be created with 1 shards and  3 replicas
   [junit4]   2> 419656 INFO  (TEST-TestTlogReplica.testAddDocs-seed#[8AC39BFFB0A0AA61]) [     ] o.a.s.c.SolrCloudTestCase active replica count: 3 expected replica count: 3
   [junit4]   2> 419656 INFO  (TEST-TestTlogReplica.testAddDocs-seed#[8AC39BFFB0A0AA61]) [     ] o.a.s.c.SolrCloudTestCase active replica count: 3 expected replica count: 3
   [junit4]   2> 419657 INFO  (TEST-TestTlogReplica.testAddDocs-seed#[8AC39BFFB0A0AA61]) [     ] o.a.s.c.SolrCloudTestCase active replica count: 3 expected replica count: 3
   [junit4]   2> 419669 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node6=1, core_node3=1, core_node5=1}, version=3}
   [junit4]   2> 419686 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t4]  webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/&wt=javabin&version=2}{add=[1 (1649197879383818240)]} 0 1
   [junit4]   2> 419687 INFO  (qtp1453265732-9920) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/&wt=javabin&version=2}{add=[1 (1649197879383818240)]} 0 2
   [junit4]   2> 419687 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1649197879383818240)]} 0 21
   [junit4]   2> 419688 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1649197879405838336,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 419688 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@7b7c4dd6 commitCommandVersion:1649197879405838336
   [junit4]   2> 419689 INFO  (qtp1453265732-9846) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node6 x:tlog_replica_test_add_docs_shard1_replica_t4 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t4]  webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
   [junit4]   2> 419689 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:40849/solr/tlog_replica_test_add_docs_shard1_replica_t2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
   [junit4]   2> 419690 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@32d6c232[tlog_replica_test_add_docs_shard1_replica_t2] main]
   [junit4]   2> 419691 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 419691 INFO  (searcherExecutor-3209-thread-1-processing-n:127.0.0.1:40849_solr x:tlog_replica_test_add_docs_shard1_replica_t2 c:tlog_replica_test_add_docs s:shard1 r:core_node5) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t2] Registered new searcher Searcher@32d6c232[tlog_replica_test_add_docs_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.4.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=13, java.vm.version=13+33, lucene.version=8.4.0, os.arch=amd64, java.runtime.version=13+33, source=flush, os.version=5.0.0-25-generic, timestamp=1572797660262}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 419691 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/update params={_stateVer_=tlog_replica_test_add_docs:6&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 3
   [junit4]   2> 419696 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
   [junit4]   2> 419702 INFO  (qtp1453265732-9920) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 419802 INFO  (qtp1453265732-9846) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 419903 INFO  (qtp1453265732-9921) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420004 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420105 INFO  (qtp1453265732-9847) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420206 INFO  (qtp1453265732-9920) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420307 INFO  (qtp1453265732-9846) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420408 INFO  (qtp1453265732-9921) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420509 INFO  (qtp1453265732-9849) [n:127.0.0.1:46815_solr c:tlog_replica_test_add_docs s:shard1 r:core_node3 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1]  webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 420548 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 420548 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Master's generation: 2
   [junit4]   2> 420548 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Master's version: 1572797660261
   [junit4]   2> 420548 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 420548 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 420548 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 420549 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
   [junit4]   2> 420549 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Number of files in latest index in master: 19
   [junit4]   2> 420549 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@7c4f2806 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2f9fd604)
   [junit4]   2> 420549 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher tmpIndexDir_type  : class org.apache.lucene.store.MockDirectoryWrapper , RAMDirectory@7c4f2806 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2f9fd604
   [junit4]   2> 420550 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420551 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420552 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420553 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420554 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Direct_0.dvdd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420554 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420555 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420555 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420556 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420557 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420557 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420558 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene80_0.dvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420558 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene80_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420559 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tix&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420559 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tbk&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420560 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420561 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Direct_0.dvdm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420561 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420562 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420562 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Bytes downloaded: 3060, Bytes skipped downloading: 0
   [junit4]   2> 420562 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=3060) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@7c4f2806 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2f9fd604)
   [junit4]   2> 420563 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 420563 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Master's generation: 2
   [junit4]   2> 420563 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Master's version: 1572797660261
   [junit4]   2> 420563 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 420563 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 420563 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 420563 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=0
   [junit4]   2> 420563 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 420564 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Number of files in latest index in master: 19
   [junit4]   2> 420564 INFO  (indexFetcher-3225-thread-1) [     ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3e1f9048[tlog_replica_test_add_docs_shard1_replica_t4] main]
   [junit4]   2> 420564 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@1dc2e1a6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@472f2f38)
   [junit4]   2> 420564 INFO  (indexFetcher-3227-thread-1) [     ] o.a.s.h.IndexFetcher tmpIndexDir_type  : class org.apache.lucene.store.MockDirectoryWrapper , RAMDirectory@1dc2e1a6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@472f2f38
   [junit4]   2> 420565 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420565 INFO  (searcherExecutor-3211-thread-1) [     ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t4] Registered new searcher Searcher@3e1f9048[tlog_replica_test_add_docs_shard1_replica_t4] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(8.4.0):C1:[diagnostics={java.vendor=Oracle Corporation, os=Linux, java.version=13, java.vm.version=13+33, lucene.version=8.4.0, os.arch=amd64, java.runtime.version=13+33, source=flush, os.version=5.0.0-25-generic, timestamp=1572797660262}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 420566 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420566 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.doc&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420567 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tim&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420567 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Direct_0.dvdd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420568 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420568 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.pos&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420569 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420570 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdx&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420570 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene50_0.tip&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420571 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fdt&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420571 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene80_0.dvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420572 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Lucene80_0.dvd&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420572 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tix&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420573 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_FSTOrd50_0.tbk&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420573 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.nvm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420574 INFO  (qtp326941180-9853) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0_Direct_0.dvdm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420574 INFO  (qtp326941180-9851) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=_0.fnm&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420575 INFO  (qtp326941180-9850) [n:127.0.0.1:40849_solr c:tlog_replica_test_add_docs s:shard1 r:core_node5 x:tlog_replica_test_add_docs_shard1_replica_t2 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t2]  webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 420575 INFO  (indexFetcher-3227-thread-1)

[...truncated too long message...]

rver Shutting down ZkTestServer.
   [junit4]   2> 500688 WARN  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	35	/solr/collections/tlog_replica_test_create_delete/terms/shard2
   [junit4]   2> 	33	/solr/collections/tlog_replica_test_create_delete/terms/shard1
   [junit4]   2> 	30	/solr/configs/conf
   [junit4]   2> 	18	/solr/collections/tlog_replica_test_remove_leader/terms/shard1
   [junit4]   2> 	16	/solr/collections/tlog_replica_test_basic_leader_election/terms/shard1
   [junit4]   2> 	15	/solr/collections/tlog_replica_test_kill_leader/terms/shard1
   [junit4]   2> 	15	/solr/collections/tlog_replica_test_kill_tlog_replica/terms/shard1
   [junit4]   2> 	12	/solr/collections/tlog_replica_test_add_docs/terms/shard1
   [junit4]   2> 	11	/solr/collections/tlog_replica_test_delete_by_id/terms/shard1
   [junit4]   2> 	10	/solr/collections/tlog_replica_test_only_leader_indexes/terms/shard1
   [junit4]   2> 	9	/solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/terms/shard1
   [junit4]   2> 	9	/solr/collections/tlog_replica_test_real_time_get/terms/shard1
   [junit4]   2> 	8	/solr/collections/tlog_replica_test_create_delete/state.json
   [junit4]   2> 	7	/solr/aliases.json
   [junit4]   2> 	6	/solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/state.json
   [junit4]   2> 	6	/solr/collections/tlog_replica_test_remove_leader/state.json
   [junit4]   2> 	6	/solr/collections/tlog_replica_test_kill_tlog_replica/state.json
   [junit4]   2> 	6	/solr/security.json
   [junit4]   2> 	5	/solr/collections/tlog_replica_test_kill_leader/state.json
   [junit4]   2> 	5	/solr/collections/tlog_replica_test_basic_leader_election/state.json
   [junit4]   2> 	5	/solr/collections/tlog_replica_test_add_remove_tlog_replica/terms/shard2
   [junit4]   2> 	5	/solr/collections/tlog_replica_test_delete_by_id/state.json
   [junit4]   2> 	4	/solr/collections/tlog_replica_test_add_docs/state.json
   [junit4]   2> 	4	/solr/collections/tlog_replica_test_add_remove_tlog_replica/terms/shard1
   [junit4]   2> 	4	/solr/collections/tlog_replica_test_real_time_get/state.json
   [junit4]   2> 	3	/solr/collections/tlog_replica_test_kill_tlog_replica/collectionprops.json
   [junit4]   2> 	3	/solr/collections/tlog_replica_test_basic_leader_election/collectionprops.json
   [junit4]   2> 	3	/solr/collections/tlog_replica_test_kill_leader/collectionprops.json
   [junit4]   2> 	3	/solr/collections/tlog_replica_test_only_leader_indexes/state.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_delete_by_id/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_recovery/state.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_recovery/terms/shard1
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_real_time_get/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_add_remove_tlog_replica/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_add_docs/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_remove_leader/collectionprops.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_only_leader_indexes/collectionprops.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	66	/solr/collections/tlog_replica_test_add_remove_tlog_replica/state.json
   [junit4]   2> 	61	/solr/collections/tlog_replica_test_create_delete/state.json
   [junit4]   2> 	52	/solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/state.json
   [junit4]   2> 	49	/solr/collections/tlog_replica_test_remove_leader/state.json
   [junit4]   2> 	46	/solr/collections/tlog_replica_test_kill_leader/state.json
   [junit4]   2> 	45	/solr/collections/tlog_replica_test_basic_leader_election/state.json
   [junit4]   2> 	43	/solr/collections/tlog_replica_test_kill_tlog_replica/state.json
   [junit4]   2> 	21	/solr/collections/tlog_replica_test_only_leader_indexes/state.json
   [junit4]   2> 	19	/solr/collections/tlog_replica_test_delete_by_id/state.json
   [junit4]   2> 	18	/solr/collections/tlog_replica_test_add_docs/state.json
   [junit4]   2> 	16	/solr/collections/tlog_replica_test_real_time_get/state.json
   [junit4]   2> 	10	/solr/clusterprops.json
   [junit4]   2> 	7	/solr/clusterstate.json
   [junit4]   2> 	5	/solr/overseer_elect/election/72420335715942407-127.0.0.1:46815_solr-n_0000000000
   [junit4]   2> 	5	/solr/collections/tlog_replica_test_recovery/state.json
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_kill_tlog_replica/leader_elect/shard1/election/72420335715942407-core_node4-n_0000000000
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard2/election/72420335715942407-core_node16-n_0000000000
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard1/election/72420335715942407-core_node5-n_0000000002
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard2/election/72420335715942407-core_node13-n_0000000000
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard1/election/72420335715942415-core_node7-n_0000000000
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard2/election/72420335715942415-core_node15-n_0000000001
   [junit4]   2> 	2	/solr/collections/tlog_replica_test_create_delete/leader_elect/shard2/election/72420335715942415-core_node11-n_0000000001
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	361	/solr/overseer/queue
   [junit4]   2> 	105	/solr/overseer/collection-queue-work
   [junit4]   2> 	85	/solr/collections
   [junit4]   2> 	31	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> 500691 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:38927
   [junit4]   2> 500691 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38927
   [junit4]   2> 500691 INFO  (SUITE-TestTlogReplica-seed#[8AC39BFFB0A0AA61]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38927
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-8.x-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestTlogReplica_8AC39BFFB0A0AA61-001
   [junit4]   2> Nov 03, 2019 4:15:41 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene80): {foo=FSTOrd50, _root_=FSTOrd50, title_s=PostingsFormat(name=LuceneFixedGap), id=Lucene50(blocksize=128), foo_s=FSTOrd50}, docValues:{_version_=DocValuesFormat(name=Lucene80), _root_=DocValuesFormat(name=Lucene80), id=DocValuesFormat(name=Direct), inplace_updatable_int=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=324, maxMBSortInHeap=6.713800221764547, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@105a1ff6), locale=bo, timezone=Asia/Samarkand
   [junit4]   2> NOTE: Linux 5.0.0-25-generic amd64/Oracle Corporation 13 (64-bit)/cpus=8,threads=1,free=338866984,total=522715136
   [junit4]   2> NOTE: All tests run in this JVM: [HdfsChaosMonkeyNothingIsSafeTest, TestDocTermOrds, OverriddenZkACLAndCredentialsProvidersTest, TestPullReplica, BJQFilterAccessibleTest, RecoveryZkTest, UnloadDistributedZkTest, RestartWhileUpdatingTest, TestSnapshotCloudManager, UniqFieldsUpdateProcessorFactoryTest, TestSearcherReuse, UUIDFieldTest, TestRTimerTree, HLLSerializationTest, TestSolrDeletionPolicy1, TestBlobHandler, BitVectorTest, TestApiFramework, DateMathParserTest, TestDocSet, NodeLostTriggerTest, CustomHighlightComponentTest, TestSolr4Spatial, TestSolrCoreProperties, TestStressVersions, HDFSCollectionsAPITest, CoreAdminRequestStatusTest, TestJsonFacets, CustomCollectionTest, TestSimExecutePlanAction, TestCrossCoreJoin, SimplePostToolTest, BufferStoreTest, TestFieldCacheReopen, RandomizedTaggerTest, IndexSizeEstimatorTest, LukeRequestHandlerTest, TestRawTransformer, TestSolrCloudWithDelegationTokens, TestHashQParserPlugin, RulesTest, TestShortCircuitedRequests, LeaderElectionTest, TermsComponentTest, TestNamedUpdateProcessors, TestIntervalFaceting, TestRuleBasedAuthorizationPlugin, UpdateParamsTest, TestTlogReplica]
   [junit4] Completed [166/880 (1!)] on J0 in 84.50s, 13 tests, 1 error <<< FAILURES!

[...truncated 47312 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-8.x-Linux/1440/consoleText

[repro] Revision: c3b8b584bf76e5bffda070d7ac704106fbd978f9

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line:  ant test  -Dtestcase=TestTlogReplica -Dtests.method=testRecovery -Dtests.seed=8AC39BFFB0A0AA61 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=bo -Dtests.timezone=Asia/Samarkand -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[repro] ant clean

[...truncated 6 lines...]
[repro] Test suites by module:
[repro]    solr/core
[repro]       TestTlogReplica
[repro] ant compile-test

[...truncated 3613 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestTlogReplica" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=8AC39BFFB0A0AA61 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=bo -Dtests.timezone=Asia/Samarkand -Dtests.asserts=true -Dtests.file.encoding=UTF-8

[...truncated 135 lines...]
[repro] Failures:
[repro]   0/5 failed: org.apache.solr.cloud.TestTlogReplica
[repro] Exiting with code 0

[...truncated 43 lines...]