lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-repro - Build # 2684 - Unstable
Date Tue, 15 Jan 2019 15:13:22 GMT
Build: https://builds.apache.org/job/Lucene-Solr-repro/2684/

[...truncated 28 lines...]
[repro] Jenkins log URL: https://builds.apache.org/job/Lucene-Solr-NightlyTests-7.x/432/consoleText

[repro] Revision: 35955b3891ed6621d5faa1c2c20ce0a333bc7b83

[repro] Ant options: -Dtests.multiplier=2 -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt
[repro] Repro line:  ant test  -Dtestcase=ForceLeaderTest -Dtests.method=testReplicasInLIRNoLeader -Dtests.seed=CD8D4CEA280B801A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.locale=en-MT -Dtests.timezone=Australia/Lindeman -Dtests.asserts=true -Dtests.file.encoding=US-ASCII

[repro] Repro line:  ant test  -Dtestcase=LIROnShardRestartTest -Dtests.method=testAllReplicasInLIR -Dtests.seed=CD8D4CEA280B801A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.locale=vi-VN -Dtests.timezone=Africa/El_Aaiun -Dtests.asserts=true -Dtests.file.encoding=US-ASCII

[repro] git rev-parse --abbrev-ref HEAD
[repro] git rev-parse HEAD
[repro] Initial local git branch/revision: d4e016afdf41baf0104f79e82d953a4650df42aa
[repro] git fetch
[repro] git checkout 35955b3891ed6621d5faa1c2c20ce0a333bc7b83

[...truncated 2 lines...]
[repro] git merge --ff-only

[...truncated 1 lines...]
[repro] ant clean

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

[...truncated 3605 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=10 -Dtests.class="*.LIROnShardRestartTest|*.ForceLeaderTest" -Dtests.showOutput=onerror -Dtests.multiplier=2 -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.seed=CD8D4CEA280B801A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.locale=vi-VN -Dtests.timezone=Africa/El_Aaiun -Dtests.asserts=true -Dtests.file.encoding=US-ASCII

[...truncated 8132 lines...]
   [junit4]   2> 304317 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase ERROR: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request. ... Sleeping for 1 seconds before re-try ...
   [junit4]   2> 305317 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=0 commError=false errorCode=510 
   [junit4]   2> 305317 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305317 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 305318 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=1 commError=false errorCode=510 
   [junit4]   2> 305318 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305318 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 305318 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=2 commError=false errorCode=510 
   [junit4]   2> 305318 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305319 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 305319 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=3 commError=false errorCode=510 
   [junit4]   2> 305319 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305319 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 305319 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=4 commError=false errorCode=510 
   [junit4]   2> 305319 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305319 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 305320 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=5 commError=false errorCode=510 
   [junit4]   2> 305320 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 305320 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase ERROR: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request. ... Sleeping for 1 seconds before re-try ...
   [junit4]   2> 306321 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=0 commError=false errorCode=510 
   [junit4]   2> 306321 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306321 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 306321 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=1 commError=false errorCode=510 
   [junit4]   2> 306322 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306322 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 306322 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=2 commError=false errorCode=510 
   [junit4]   2> 306322 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306322 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 306323 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=3 commError=false errorCode=510 
   [junit4]   2> 306323 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306323 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 306323 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=4 commError=false errorCode=510 
   [junit4]   2> 306323 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306323 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 306324 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=5 commError=false errorCode=510 
   [junit4]   2> 306324 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 306324 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase ERROR: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request. ... Sleeping for 1 seconds before re-try ...
   [junit4]   2> 307325 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=0 commError=false errorCode=510 
   [junit4]   2> 307325 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307325 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 307325 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=1 commError=false errorCode=510 
   [junit4]   2> 307325 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307325 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 307326 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=2 commError=false errorCode=510 
   [junit4]   2> 307326 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307326 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 307341 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=3 commError=false errorCode=510 
   [junit4]   2> 307341 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307341 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 307342 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=4 commError=false errorCode=510 
   [junit4]   2> 307342 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307342 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 307342 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=5 commError=false errorCode=510 
   [junit4]   2> 307342 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 307342 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase ERROR: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request. ... Sleeping for 1 seconds before re-try ...
   [junit4]   2> 308348 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=0 commError=false errorCode=510 
   [junit4]   2> 308348 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308348 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 308348 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=1 commError=false errorCode=510 
   [junit4]   2> 308348 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308348 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 308349 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=2 commError=false errorCode=510 
   [junit4]   2> 308349 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308349 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 308349 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=3 commError=false errorCode=510 
   [junit4]   2> 308349 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308349 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 308350 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=4 commError=false errorCode=510 
   [junit4]   2> 308350 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308350 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 308351 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=5 commError=false errorCode=510 
   [junit4]   2> 308351 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 308351 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase ERROR: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request. ... Sleeping for 1 seconds before re-try ...
   [junit4]   2> 309351 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=0 commError=false errorCode=510 
   [junit4]   2> 309352 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309352 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 309352 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=1 commError=false errorCode=510 
   [junit4]   2> 309352 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309352 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 309352 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=2 commError=false errorCode=510 
   [junit4]   2> 309352 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309352 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 309355 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=3 commError=false errorCode=510 
   [junit4]   2> 309355 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309355 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 309356 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=4 commError=false errorCode=510 
   [junit4]   2> 309373 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309373 WARN  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Re-trying request to collection(s) [forceleader_lower_terms_collection] after stale state error from server.
   [junit4]   2> 309373 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient Request to collection [forceleader_lower_terms_collection] failed due to (510) org.apache.solr.common.SolrException: Could not find a healthy node to handle the request., retry=5 commError=false errorCode=510 
   [junit4]   2> 309373 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.CloudSolrClient request was not communication error it seems
   [junit4]   2> 309373 ERROR (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractFullDistribZkTestBase No more retries available! Add batch failed due to: org.apache.solr.common.SolrException: Could not find a healthy node to handle the request.
   [junit4]   2> 309373 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest Document couldn't be sent, which is expected.
   [junit4]   2> 309373 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest Do force leader...
   [junit4]   2> 309421 INFO  (zkConnectionManagerCallback-345-thread-1) [    ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 309423 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 309424 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:39550/solr ready
   [junit4]   2> 309424 INFO  (SocketProxy-Acceptor-34221) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=50940,localport=34221], receiveBufferSize:531000
   [junit4]   2> 309441 INFO  (SocketProxy-Acceptor-34221) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=43539,localport=39400], receiveBufferSize=530904
   [junit4]   2> 309442 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_    ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :forceleader with params action=FORCELEADER&collection=forceleader_lower_terms_collection&shard=shard1&wt=javabin&version=2 and sendToOCPQueue=true
   [junit4]   2> 309442 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.h.a.CollectionsHandler Force leader invoked, state: znodeVersion: 0
   [junit4]   2> live nodes:[127.0.0.1:34221_, 127.0.0.1:36697_, 127.0.0.1:41620_]
   [junit4]   2> collections:{collection1=DocCollection(collection1//collections/collection1/state.json/10)={
   [junit4]   2>   "pullReplicas":"0",
   [junit4]   2>   "replicationFactor":"1",
   [junit4]   2>   "shards":{
   [junit4]   2>     "shard1":{
   [junit4]   2>       "range":"80000000-ffffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{"core_node3":{
   [junit4]   2>           "core":"collection1_shard1_replica_n2",
   [junit4]   2>           "base_url":"http://127.0.0.1:41173",
   [junit4]   2>           "node_name":"127.0.0.1:41173_",
   [junit4]   2>           "state":"down",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "leader":"true"}}},
   [junit4]   2>     "shard2":{
   [junit4]   2>       "range":"0-7fffffff",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "replicas":{
   [junit4]   2>         "core_node4":{
   [junit4]   2>           "core":"collection1_shard2_replica_n1",
   [junit4]   2>           "base_url":"http://127.0.0.1:36697",
   [junit4]   2>           "node_name":"127.0.0.1:36697_",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT",
   [junit4]   2>           "leader":"true"},
   [junit4]   2>         "core_node6":{
   [junit4]   2>           "core":"collection1_shard2_replica_n5",
   [junit4]   2>           "base_url":"http://127.0.0.1:34221",
   [junit4]   2>           "node_name":"127.0.0.1:34221_",
   [junit4]   2>           "state":"active",
   [junit4]   2>           "type":"NRT"}}}},
   [junit4]   2>   "router":{"name":"compositeId"},
   [junit4]   2>   "maxShardsPerNode":"1",
   [junit4]   2>   "autoAddReplicas":"false",
   [junit4]   2>   "nrtReplicas":"1",
   [junit4]   2>   "tlogReplicas":"0"}, forceleader_lower_terms_collection=LazyCollectionRef(forceleader_lower_terms_collection), control_collection=LazyCollectionRef(control_collection)}
   [junit4]   2> 309523 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forceleader_lower_terms_collection/terms/shard1 to Terms{values={core_node6=1, core_node4=2, core_node5=2}, version=5}
   [junit4]   2> 309523 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forceleader_lower_terms_collection/terms/shard1 to Terms{values={core_node6=2, core_node4=2, core_node5=2}, version=6}
   [junit4]   2> 309660 INFO  (qtp1969362116-877) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n5:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 309662 INFO  (qtp1969362116-879) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n5:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 309663 INFO  (qtp1969362116-878) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n5:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 309689 INFO  (qtp1969362116-876) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309691 INFO  (qtp1969362116-877) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309693 INFO  (qtp1969362116-879) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309701 INFO  (qtp1969362116-878) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309703 INFO  (qtp1969362116-876) [n:127.0.0.1:34221_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309704 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=51486,localport=36697], receiveBufferSize:531000
   [junit4]   2> 309704 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=42896,localport=51084], receiveBufferSize=530904
   [junit4]   2> 309730 INFO  (qtp210357670-941) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=21
   [junit4]   2> 309752 INFO  (qtp210357670-939) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=15
   [junit4]   2> 309753 INFO  (qtp210357670-943) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.collection1.shard2.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n2:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 309755 INFO  (qtp210357670-940) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
   [junit4]   2> 309771 INFO  (qtp210357670-936) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
   [junit4]   2> 309787 INFO  (qtp210357670-1061) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
   [junit4]   2> 309806 INFO  (qtp210357670-941) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=17
   [junit4]   2> 309809 INFO  (qtp210357670-941) [n:127.0.0.1:36697_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
   [junit4]   2> 309822 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=46526,localport=41620], receiveBufferSize:531000
   [junit4]   2> 309846 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=38290,localport=55580], receiveBufferSize=530904
   [junit4]   2> 309860 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.control_collection.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=18
   [junit4]   2> 309875 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.control_collection.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=13
   [junit4]   2> 309879 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.control_collection.shard1.replica_n1:INDEX.sizeInBytes&key=solr.core.forceleader_lower_terms_collection.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
   [junit4]   2> 309881 INFO  (qtp2020964948-807) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0
   [junit4]   2> 309915 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=17
   [junit4]   2> 309933 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=14
   [junit4]   2> 309968 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=33
   [junit4]   2> 309970 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=1
   [junit4]   2> 310027 INFO  (AutoscalingActionExecutor-221-thread-1) [    ] o.a.s.c.a.ExecutePlanAction No operations to execute for event: {
   [junit4]   2>   "id":"6a3bea55e8a46fT715vak6m1aucywurtigw3e1pw",
   [junit4]   2>   "source":".auto_add_replicas",
   [junit4]   2>   "eventTime":29902225181025391,
   [junit4]   2>   "eventType":"NODELOST",
   [junit4]   2>   "properties":{
   [junit4]   2>     "eventTimes":[29902225181025391],
   [junit4]   2>     "preferredOperation":"movereplica",
   [junit4]   2>     "_enqueue_time_":29902235287465555,
   [junit4]   2>     "nodeNames":["127.0.0.1:41173_"]}}
   [junit4]   2> 314314 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 314315 WARN  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.RecoveryStrategy Stopping recovery for core=[forceleader_lower_terms_collection_shard1_replica_n1] coreNodeName=[core_node4]
   [junit4]   2> 314524 WARN  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.h.a.CollectionsHandler Force leader attempt 1. Waiting 5 secs for an active leader. State of the slice: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node4":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:41620",
   [junit4]   2>       "node_name":"127.0.0.1:41620_",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node5":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n3",
   [junit4]   2>       "base_url":"http://127.0.0.1:41173",
   [junit4]   2>       "node_name":"127.0.0.1:41173_",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node6":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n2",
   [junit4]   2>       "base_url":"http://127.0.0.1:36697",
   [junit4]   2>       "node_name":"127.0.0.1:36697_",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 316815 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/
   [junit4]   2> 316815 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=forceleader_lower_terms_collection_shard1_replica_n1 url=http://127.0.0.1:41620 START replicas=[http://127.0.0.1:36697/forceleader_lower_terms_collection_shard1_replica_n2/] nUpdates=100
   [junit4]   2> 316818 INFO  (qtp210357670-939) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n2]  webapp= path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 316819 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=forceleader_lower_terms_collection_shard1_replica_n1 url=http://127.0.0.1:41620  Received 1 versions from http://127.0.0.1:36697/forceleader_lower_terms_collection_shard1_replica_n2/ fingerprint:null
   [junit4]   2> 316819 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=forceleader_lower_terms_collection_shard1_replica_n1 url=http://127.0.0.1:41620  No additional versions requested. ourHighThreshold=1622739329278279680 otherLowThreshold=1622739329278279680 ourHighest=1622739329278279680 otherHighest=1622739329278279680
   [junit4]   2> 316819 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.PeerSync PeerSync: core=forceleader_lower_terms_collection_shard1_replica_n1 url=http://127.0.0.1:41620 DONE. sync succeeded
   [junit4]   2> 316819 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 316819 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/: try and ask http://127.0.0.1:36697/forceleader_lower_terms_collection_shard1_replica_n2/ to sync
   [junit4]   2> 316821 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.PeerSync PeerSync: core=forceleader_lower_terms_collection_shard1_replica_n2 url=http://127.0.0.1:36697 START replicas=[http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/] nUpdates=100
   [junit4]   2> 316822 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=46600,localport=41620], receiveBufferSize:531000
   [junit4]   2> 316822 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=38290,localport=55654], receiveBufferSize=530904
   [junit4]   2> 316917 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@6917e2d0[forceleader_lower_terms_collection_shard1_replica_n1] realtime]
   [junit4]   2> 316917 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.IndexFingerprint IndexFingerprint millis:94.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=1622739329278279680, maxInHash=1622739329278279680, versionsHash=-2795804146055088105, numVersions=1, numDocs=1, maxDoc=1}
   [junit4]   2> 316917 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/get params={distrib=false&qt=/get&getFingerprint=9223372036854775807&wt=javabin&version=2} status=0 QTime=94
   [junit4]   2> 316962 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@76e91609[forceleader_lower_terms_collection_shard1_replica_n2] realtime]
   [junit4]   2> 316963 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.IndexFingerprint IndexFingerprint millis:44.0 result:{maxVersionSpecified=9223372036854775807, maxVersionEncountered=1622739329278279680, maxInHash=1622739329278279680, versionsHash=-2795804146055088105, numVersions=1, numDocs=1, maxDoc=1}
   [junit4]   2> 316963 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.PeerSync We are already in sync. No need to do a PeerSync 
   [junit4]   2> 316963 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n2]  webapp= path=/get params={distrib=false&qt=/get&getVersions=100&sync=http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/&wt=javabin&version=2} status=0 QTime=142
   [junit4]   2> 316963 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/:  sync completed with http://127.0.0.1:36697/forceleader_lower_terms_collection_shard1_replica_n2/
   [junit4]   2> 316964 ERROR (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext WARNING: Potential data loss -- Replica core_node4 became leader after timeout (leaderVoteWait) without being up-to-date with the previous leader
   [junit4]   2> 316964 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/forceleader_lower_terms_collection/leaders/shard1/leader after winning as /collections/forceleader_lower_terms_collection/leader_elect/shard1/election/74017263731146756-core_node4-n_0000000001
   [junit4]   2> 316967 INFO  (zkCallback-324-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 316967 INFO  (zkCallback-265-thread-3) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 316967 INFO  (zkCallback-265-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 316967 INFO  (zkCallback-265-thread-2) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/ shard1
   [junit4]   2> 317094 INFO  (zkCallback-324-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317094 INFO  (zkCallback-265-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317094 INFO  (zkCallback-265-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317387 INFO  (recoveryExecutor-262-thread-1-processing-n:127.0.0.1:41620_ x:forceleader_lower_terms_collection_shard1_replica_n1 c:forceleader_lower_terms_collection s:shard1 r:core_node4) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.RecoveryStrategy RecoveryStrategy has been closed
   [junit4]   2> 317387 INFO  (recoveryExecutor-262-thread-1-processing-n:127.0.0.1:41620_ x:forceleader_lower_terms_collection_shard1_replica_n1 c:forceleader_lower_terms_collection s:shard1 r:core_node4) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.RecoveryStrategy Finished recovery process, successful=[false]
   [junit4]   2> 317404 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=46608,localport=41620], receiveBufferSize:531000
   [junit4]   2> 317405 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=38290,localport=55662], receiveBufferSize=530904
   [junit4]   2> 317407 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/admin/ping params={wt=javabin&version=2} hits=0 status=0 QTime=1
   [junit4]   2> 317407 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/admin/ping params={wt=javabin&version=2} status=0 QTime=1
   [junit4]   2> 317407 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Begin buffering updates. core=[forceleader_lower_terms_collection_shard1_replica_n2]
   [junit4]   2> 317408 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/solr/build/solr-core/test/J0/temp/solr.cloud.ForceLeaderTest_CD8D4CEA280B801A-002/shard-3-001/cores/forceleader_lower_terms_collection_shard1_replica_n2/data/tlog/tlog.0000000000000000000 refcount=1}}
   [junit4]   2> 317408 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Publishing state of core [forceleader_lower_terms_collection_shard1_replica_n2] as recovering, leader is [http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/] and I am [http://127.0.0.1:36697/forceleader_lower_terms_collection_shard1_replica_n2/]
   [junit4]   2> 317409 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forceleader_lower_terms_collection/terms/shard1 to Terms{values={core_node6=2, core_node6_recovering=2, core_node4=2, core_node5=2}, version=7}
   [junit4]   2> 317411 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Sending prep recovery command to [http://127.0.0.1:41620]; [WaitForState: action=PREPRECOVERY&core=forceleader_lower_terms_collection_shard1_replica_n1&nodeName=127.0.0.1:36697_&coreNodeName=core_node6&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true]
   [junit4]   2> 317412 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node6, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 317412 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=forceleader_lower_terms_collection, shard=shard1, thisCore=forceleader_lower_terms_collection_shard1_replica_n1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:36697_, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{"core":"forceleader_lower_terms_collection_shard1_replica_n2","base_url":"http://127.0.0.1:36697","node_name":"127.0.0.1:36697_","state":"down","type":"NRT"}
   [junit4]   2> 317512 INFO  (zkCallback-265-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317512 INFO  (zkCallback-324-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317512 INFO  (zkCallback-265-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 317513 INFO  (watches-267-thread-1) [    ] o.a.s.h.a.PrepRecoveryOp In WaitForState(recovering): collection=forceleader_lower_terms_collection, shard=shard1, thisCore=forceleader_lower_terms_collection_shard1_replica_n1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=recovering, localState=active, nodeName=127.0.0.1:36697_, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{"core":"forceleader_lower_terms_collection_shard1_replica_n2","base_url":"http://127.0.0.1:36697","node_name":"127.0.0.1:36697_","state":"recovering","type":"NRT"}
   [junit4]   2> 317513 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_    x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:36697_&onlyIfLeaderActive=true&core=forceleader_lower_terms_collection_shard1_replica_n1&coreNodeName=core_node6&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=101
   [junit4]   2> 318014 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Attempting to PeerSync from [http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/] - recoveringAfterStartup=[true]
   [junit4]   2> 318014 WARN  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.PeerSyncWithLeader no frame of reference to tell if we've missed updates
   [junit4]   2> 318014 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy PeerSync Recovery was not successful - trying replication.
   [junit4]   2> 318014 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Starting Replication Recovery.
   [junit4]   2> 318014 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Attempting to replicate from [http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/].
   [junit4]   2> 318018 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1622739352668864512,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 318018 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@46149f8c commitCommandVersion:1622739352668864512
   [junit4]   2> 318108 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=51576,localport=36697], receiveBufferSize:531000
   [junit4]   2> 318177 INFO  (qtp210357670-936) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.p.DistributedUpdateProcessor Ignoring commit while not ACTIVE - state: BUFFERING replay: false
   [junit4]   2> 318177 INFO  (qtp210357670-936) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n2]  webapp= path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=false&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
   [junit4]   2> 318230 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=42896,localport=51174], receiveBufferSize=530904
   [junit4]   2> 318249 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d1bdbbb[forceleader_lower_terms_collection_shard1_replica_n1] realtime]
   [junit4]   2> 318249 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 318250 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 232
   [junit4]   2> 318254 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0
   [junit4]   2> 318265 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Master's generation: 2
   [junit4]   2> 318265 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Master's version: 1547564842862
   [junit4]   2> 318265 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Slave's generation: 1
   [junit4]   2> 318265 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Slave's version: 0
   [junit4]   2> 318265 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Starting replication process
   [junit4]   2> 318268 INFO  (qtp2020964948-807) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=2
   [junit4]   2> 318268 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Number of files in latest index in master: 4
   [junit4]   2> 318270 WARN  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher File _0.cfe did not match. expected checksum is 217746480 and actual is checksum 2259273683. expected length is 405 and actual length is 405
   [junit4]   2> 318270 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Starting download (fullCopy=true) to MockDirectoryWrapper(RAMDirectory@603ecf6f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@61838960)
   [junit4]   2> 318270 WARN  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher File _0.cfe did not match. expected checksum is 217746480 and actual is checksum 2259273683. expected length is 405 and actual length is 405
   [junit4]   2> 318271 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={generation=2&qt=/replication&file=_0.cfe&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 318312 WARN  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher File _0.si did not match. expected checksum is 4057686650 and actual is checksum 950829739. expected length is 384 and actual length is 384
   [junit4]   2> 318313 INFO  (qtp2020964948-810) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={generation=2&qt=/replication&file=_0.si&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 318379 WARN  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher File _0.cfs did not match. expected checksum is 4217339397 and actual is checksum 3702554546. expected length is 3122 and actual length is 3122
   [junit4]   2> 318381 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={generation=2&qt=/replication&file=_0.cfs&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 318416 INFO  (qtp2020964948-808) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0
   [junit4]   2> 318455 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Bytes downloaded: 4114, Bytes skipped downloading: 0
   [junit4]   2> 318455 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=true,bytesDownloaded=4114) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@603ecf6f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@61838960)
   [junit4]   2> 318463 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.SolrCore Updating index properties... index=index.20190115150723112
   [junit4]   2> 318464 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.h.IndexFetcher removing old index directory MockDirectoryWrapper(RAMDirectory@61aa019e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@306ac01a)
   [junit4]   2> 318467 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2105231426, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 318468 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
   [junit4]   2> 318469 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@416c149b[forceleader_lower_terms_collection_shard1_replica_n2] main]
   [junit4]   2> 318486 INFO  (searcherExecutor-280-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.SolrCore [forceleader_lower_terms_collection_shard1_replica_n2] Registered new searcher Searcher@416c149b[forceleader_lower_terms_collection_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.7.0):c1:[diagnostics={java.runtime.version=1.8.0_191-b12, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=7.7.0, os=Linux, os.arch=amd64, os.version=4.4.0-112-generic, source=flush, timestamp=1547564841670}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 318504 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy No replay needed.
   [junit4]   2> 318504 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Replication Recovery was successful.
   [junit4]   2> 318504 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Registering as Active after recovery.
   [junit4]   2> 318509 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forceleader_lower_terms_collection/terms/shard1 to Terms{values={core_node6=2, core_node4=2, core_node5=2}, version=8}
   [junit4]   2> 318509 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Updating version bucket highest from index after successful recovery.
   [junit4]   2> 318640 INFO  (recoveryExecutor-321-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.RecoveryStrategy Finished recovery process, successful=[true]
   [junit4]   2> 318715 INFO  (zkCallback-324-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 318715 INFO  (zkCallback-265-thread-2) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 318715 INFO  (zkCallback-265-thread-1) [    ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/forceleader_lower_terms_collection/state.json] for collection [forceleader_lower_terms_collection] has occurred - updating... (live nodes size: [3])
   [junit4]   2> 319525 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.h.a.CollectionsHandler Successfully issued FORCELEADER command for collection: forceleader_lower_terms_collection, shard: shard1
   [junit4]   2> 319525 INFO  (qtp1969362116-875) [n:127.0.0.1:34221_ c:forceleader_lower_terms_collection   ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=FORCELEADER&collection=forceleader_lower_terms_collection&shard=shard1&wt=javabin&version=2} status=0 QTime=10083
   [junit4]   2> 319528 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: forceleader_lower_terms_collection failOnTimeout:true timeout (sec):330
   [junit4]   1> replica:core_node4 rstate:active live:true
   [junit4]   1> replica:core_node4 rstate:active live:true
   [junit4]   1> replica:core_node5 rstate:down live:false
   [junit4]   1> replica:core_node6 rstate:active live:true
   [junit4]   1> no one is recoverying
   [junit4]   1> replica:core_node5 rstate:down live:false
   [junit4]   1> replica:core_node6 rstate:active live:true
   [junit4]   1> no one is recoverying
   [junit4]   2> 319566 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: forceleader_lower_terms_collection
   [junit4]   2> 319569 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest After forcing leader: shard1:{
   [junit4]   2>   "range":"80000000-7fffffff",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "replicas":{
   [junit4]   2>     "core_node4":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n1",
   [junit4]   2>       "base_url":"http://127.0.0.1:41620",
   [junit4]   2>       "node_name":"127.0.0.1:41620_",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "type":"NRT",
   [junit4]   2>       "leader":"true"},
   [junit4]   2>     "core_node5":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n3",
   [junit4]   2>       "base_url":"http://127.0.0.1:41173",
   [junit4]   2>       "node_name":"127.0.0.1:41173_",
   [junit4]   2>       "state":"down",
   [junit4]   2>       "type":"NRT"},
   [junit4]   2>     "core_node6":{
   [junit4]   2>       "core":"forceleader_lower_terms_collection_shard1_replica_n2",
   [junit4]   2>       "base_url":"http://127.0.0.1:36697",
   [junit4]   2>       "node_name":"127.0.0.1:36697_",
   [junit4]   2>       "state":"active",
   [junit4]   2>       "type":"NRT"}}}
   [junit4]   2> 319610 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest Sending doc 4...
   [junit4]   2> 319762 INFO  (qtp2020964948-807) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/forceleader_lower_terms_collection/terms/shard1 to Terms{values={core_node6=3, core_node4=3, core_node5=2}, version=9}
   [junit4]   2> 319906 INFO  (qtp210357670-1061) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n2]  webapp= path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/&wt=javabin&version=2}{add=[4 (1622739354364411904)]} 0 159
   [junit4]   2> 319907 INFO  (qtp2020964948-807) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/update params={wt=javabin&version=2}{add=[4 (1622739354364411904)]} 0 272
   [junit4]   2> 319907 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest Committing...
   [junit4]   2> 319926 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1622739354669547520,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 319947 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@46149f8c commitCommandVersion:1622739354669547520
   [junit4]   2> 319967 INFO  (qtp210357670-941) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1622739354712539136,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 319967 INFO  (qtp210357670-941) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@54f2cd95 commitCommandVersion:1622739354712539136
   [junit4]   2> 319990 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@26774c84[forceleader_lower_terms_collection_shard1_replica_n1] main]
   [junit4]   2> 320050 INFO  (qtp210357670-941) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.s.SolrIndexSearcher Opening [Searcher@1d5e863[forceleader_lower_terms_collection_shard1_replica_n2] main]
   [junit4]   2> 320050 INFO  (qtp210357670-941) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 320052 INFO  (searcherExecutor-275-thread-1-processing-n:127.0.0.1:41620_ x:forceleader_lower_terms_collection_shard1_replica_n1 c:forceleader_lower_terms_collection s:shard1 r:core_node4) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.SolrCore [forceleader_lower_terms_collection_shard1_replica_n1] Registered new searcher Searcher@26774c84[forceleader_lower_terms_collection_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.7.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=7.7.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1547564841670}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(7.7.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=7.7.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1547564844811}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 320052 INFO  (searcherExecutor-280-thread-1-processing-n:127.0.0.1:36697_ x:forceleader_lower_terms_collection_shard1_replica_n2 c:forceleader_lower_terms_collection s:shard1 r:core_node6) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.c.SolrCore [forceleader_lower_terms_collection_shard1_replica_n2] Registered new searcher Searcher@1d5e863[forceleader_lower_terms_collection_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.7.0):c1:[diagnostics={java.runtime.version=1.8.0_191-b12, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=7.7.0, os=Linux, os.arch=amd64, os.version=4.4.0-112-generic, source=flush, timestamp=1547564841670}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}]) Uninverting(_1(7.7.0):c1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, java.version=1.8.0_191, java.vm.version=25.191-b12, lucene.version=7.7.0, os.arch=amd64, java.runtime.version=1.8.0_191-b12, source=flush, os.version=4.4.0-112-generic, timestamp=1547564844834}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
   [junit4]   2> 320053 INFO  (qtp210357670-941) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forceleader_lower_terms_collection_shard1_replica_n2] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n2]  webapp= path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41620/forceleader_lower_terms_collection_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 85
   [junit4]   2> 320088 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 320104 INFO  (qtp2020964948-809) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.u.p.LogUpdateProcessorFactory [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/update params={_stateVer_=forceleader_lower_terms_collection:14&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 178
   [junit4]   2> 320107 INFO  (TEST-ForceLeaderTest.testReplicasInLowerTerms-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ForceLeaderTest Doc 4 sent and commit issued
   [junit4]   2> 320110 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=46622,localport=41620], receiveBufferSize:531000
   [junit4]   2> 320111 INFO  (SocketProxy-Acceptor-41620) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=38290,localport=55676], receiveBufferSize=530904
   [junit4]   2> 320157 INFO  (qtp2020964948-811) [n:127.0.0.1:41620_ c:forceleader_lower_terms_collection s:shard1 r:core_node4 x:forceleader_lower_terms_collection_shard1_replica_n1] o.a.s.c.S.Request [forceleader_lower_terms_collection_shard1_replica_n1]  webapp= path=/get params={distrib=false&qt=/get&id=1&wt=javabin&version=2} status=0 QTime=33
   [junit4]   2> 320161 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy accepted Socket[addr=/127.0.0.1,port=51590,localport=36697], receiveBufferSize:531000
   [junit4]   2> 320177 INFO  (SocketProxy-Acceptor-36697) [    ] o.a.s.c.s.c.SocketProxy proxy connection Socket[addr=/127.0.0.1,port=42896,localport=51188], receiveBufferSize=530904
   [junit4]   2> 320179 INFO  (qtp210357670-943) [n:127.0.0.1:36697_ c:forceleader_lower_terms_collection s:shard1 r:core_node6 x:forcelead

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

casInLIRNoLeader-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
   [junit4]   2> 513540 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> 	14	/solr/collections/collection1/state.json
   [junit4]   2> 	11	/solr/aliases.json
   [junit4]   2> 	9	/solr/collections/collection1/terms/shard2
   [junit4]   2> 	5	/solr/collections/forceleader_test_collection/terms/shard1
   [junit4]   2> 	4	/solr/security.json
   [junit4]   2> 	4	/solr/configs/conf1
   [junit4]   2> 	2	/solr/collections/collection1/terms/shard1
   [junit4]   2> 	2	/solr/collections/control_collection/terms/shard1
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	100	/solr/collections/forceleader_test_collection/state.json
   [junit4]   2> 	11	/solr/clusterprops.json
   [junit4]   2> 	11	/solr/clusterstate.json
   [junit4]   2> 	9	/solr/collections/control_collection/state.json
   [junit4]   2> 	2	/solr/overseer_elect/election/74017268443119626-127.0.0.1:34750_-n_0000000001
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	11	/solr/collections
   [junit4]   2> 	10	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> 513543 INFO  (TEST-ForceLeaderTest.testReplicasInLIRNoLeader-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37583
   [junit4]   2> 513543 INFO  (TEST-ForceLeaderTest.testReplicasInLIRNoLeader-seed#[CD8D4CEA280B801A]) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37583
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ForceLeaderTest -Dtests.method=testReplicasInLIRNoLeader -Dtests.seed=CD8D4CEA280B801A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.badapples=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-7.x/test-data/enwiki.random.lines.txt -Dtests.locale=vi-VN -Dtests.timezone=Africa/El_Aaiun -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR    181s J0 | ForceLeaderTest.testReplicasInLIRNoLeader <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:38908/forceleader_test_collection
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([CD8D4CEA280B801A:2B1A782A1189797B]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:654)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:255)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:244)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:484)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:414)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1110)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:884)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:194)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.commit(SolrClient.java:504)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.commit(SolrClient.java:479)
   [junit4]    > 	at org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader(ForceLeaderTest.java:294)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1063)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1035)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]    > Caused by: java.net.SocketTimeoutException: Read timed out
   [junit4]    > 	at java.net.SocketInputStream.socketRead0(Native Method)
   [junit4]    > 	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
   [junit4]    > 	at java.net.SocketInputStream.read(SocketInputStream.java:171)
   [junit4]    > 	at java.net.SocketInputStream.read(SocketInputStream.java:141)
   [junit4]    > 	at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
   [junit4]    > 	at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
   [junit4]    > 	at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:282)
   [junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
   [junit4]    > 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
   [junit4]    > 	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
   [junit4]    > 	at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
   [junit4]    > 	at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:165)
   [junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
   [junit4]    > 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
   [junit4]    > 	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
   [junit4]    > 	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:185)
   [junit4]    > 	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
   [junit4]    > 	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
   [junit4]    > 	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
   [junit4]    > 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
   [junit4]    > 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:542)
   [junit4]    > 	... 52 more
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/solr/build/solr-core/test/J0/temp/solr.cloud.ForceLeaderTest_CD8D4CEA280B801A-002
   [junit4]   2> Jan 15, 2019 3:10:38 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene70, sim=RandomSimilarity(queryNorm=false): {}, locale=vi-VN, timezone=Africa/El_Aaiun
   [junit4]   2> NOTE: Linux 4.4.0-112-generic amd64/Oracle Corporation 1.8.0_191 (64-bit)/cpus=4,threads=1,free=277475944,total=535822336
   [junit4]   2> NOTE: All tests run in this JVM: [ForceLeaderTest, LIROnShardRestartTest, ForceLeaderTest]
   [junit4] Completed [10/10 (6!)] on J0 in 254.08s, 3 tests, 1 error, 1 skipped <<< FAILURES!
   [junit4] 
   [junit4] 
   [junit4] Tests with failures [seed: CD8D4CEA280B801A] (first 10 out of 11):
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLowerTerms
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLowerTerms
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLowerTerms
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader
   [junit4]   - org.apache.solr.cloud.ForceLeaderTest.testReplicasInLIRNoLeader
   [junit4]   - org.apache.solr.cloud.LIROnShardRestartTest.testAllReplicasInLIR
   [junit4]   - org.apache.solr.cloud.LIROnShardRestartTest.testSeveralReplicasInLIR
   [junit4]   - org.apache.solr.cloud.LIROnShardRestartTest.testAllReplicasInLIR
   [junit4]   - org.apache.solr.cloud.LIROnShardRestartTest.testSeveralReplicasInLIR
   [junit4] 
   [junit4] 
   [junit4] JVM J0:     2.90 ..   660.43 =   657.53s
   [junit4] JVM J1:     2.92 ..   502.61 =   499.69s
   [junit4] JVM J2:     2.89 ..   427.22 =   424.33s
   [junit4] Execution time total: 11 minutes
   [junit4] Tests summary: 10 suites, 25 tests, 11 errors, 5 ignored

BUILD FAILED
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/lucene/common-build.xml:1572: The following error occurred while executing this line:
/home/jenkins/jenkins-slave/workspace/Lucene-Solr-repro/lucene/common-build.xml:1099: There were test failures: 10 suites, 25 tests, 11 errors, 5 ignored [seed: CD8D4CEA280B801A]

Total time: 11 minutes 9 seconds

[repro] Setting last failure code to 256

[repro] Failures:
[repro]   2/5 failed: org.apache.solr.cloud.LIROnShardRestartTest
[repro]   4/5 failed: org.apache.solr.cloud.ForceLeaderTest
[repro] git checkout d4e016afdf41baf0104f79e82d953a4650df42aa
Previous HEAD position was 35955b3... LUCENE-8623: Decrease I/O pressure when merging high dimensional points
HEAD is now at d4e016a... LUCENE-8474: (partial) removal of accesses to RAMFile and RAMDirectory streams. Removal of GrowableByteArrayDataOutput.
[repro] Exiting with code 256
Archiving artifacts
[Fast Archiver] No artifacts from Lucene-Solr-repro Repro-Lucene-Solr-SmokeRelease-7.x#428 to compare, so performing full copy of artifacts
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)

Mime
View raw message