Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/988/
Java: 64bit/jdk-9 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
FAILED:  org.apache.solr.cloud.TestRequestForwarding.testMultiCollectionQuery

Error Message:
Query 'q=cat%3Afootball%5E2' failed, 

Stack Trace:
java.lang.RuntimeException: Query 'q=cat%3Afootball%5E2' failed, 
        at 
__randomizedtesting.SeedInfo.seed([E2806E7B5D694F99:F3F3A94A811F4AE5]:0)
        at 
org.apache.solr.cloud.TestRequestForwarding.testMultiCollectionQuery(TestRequestForwarding.java:67)
        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.base/java.lang.reflect.Method.invoke(Method.java:564)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.base/java.lang.Thread.run(Thread.java:844)
Caused by: java.io.IOException: Server returned HTTP response code: 503 for 
URL: http://127.0.0.1:60098/solr/collection1/select?q=cat%3Afootball%5E2
        at 
java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1895)
        at 
java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1491)
        at java.base/java.net.URL.openStream(URL.java:1117)
        at 
org.apache.solr.cloud.TestRequestForwarding.testMultiCollectionQuery(TestRequestForwarding.java:65)
        ... 38 more




Build Log:
[...truncated 14272 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestRequestForwarding
   [junit4]   2> 1995324 INFO  
(SUITE-TestRequestForwarding-seed#[E2806E7B5D694F99]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/init-core-data-001
   [junit4]   2> 1995325 WARN  
(SUITE-TestRequestForwarding-seed#[E2806E7B5D694F99]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=11 numCloses=11
   [junit4]   2> 1995325 INFO  
(SUITE-TestRequestForwarding-seed#[E2806E7B5D694F99]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) 
w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 1995326 INFO  
(SUITE-TestRequestForwarding-seed#[E2806E7B5D694F99]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl="None") w/ MAC_OS_X 
supressed clientAuth
   [junit4]   2> 1995328 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.SolrTestCaseJ4 ###Starting testMultiCollectionQuery
   [junit4]   2> 1995329 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001
   [junit4]   2> 1995329 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 1995330 INFO  (ZkTestServer Run Thread) [    ] 
o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1995330 INFO  (ZkTestServer Run Thread) [    ] 
o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 1995432 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer start zk server on port:60091
   [junit4]   2> 1995432 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:60091
   [junit4]   2> 1995432 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 60091
   [junit4]   2> 1995450 INFO  (zkConnectionManagerCallback-15548-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995454 INFO  (zkConnectionManagerCallback-15550-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995458 INFO  (zkConnectionManagerCallback-15552-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995461 WARN  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 1995462 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 1995462 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 1995462 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: 
c4550056e785fb5665914545889f21dc136ad9e6; jvm 9+181
   [junit4]   2> 1995462 WARN  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 1995463 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 1995477 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 1995477 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: 
c4550056e785fb5665914545889f21dc136ad9e6; jvm 9+181
   [junit4]   2> 1995485 WARN  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: 
c4550056e785fb5665914545889f21dc136ad9e6; jvm 9+181
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1995486 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 1995487 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1995487 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1995487 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.session node0 Scavenging every 600000ms
   [junit4]   2> 1995488 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@752ddbf7{/solr,null,AVAILABLE}
   [junit4]   2> 1995489 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@69d9b7a5{/solr,null,AVAILABLE}
   [junit4]   2> 1995490 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 1995490 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 1995490 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 1995490 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@2656aa5c{/solr,null,AVAILABLE}
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@19fe87c6{HTTP/1.1,[http/1.1]}{127.0.0.1:60096}
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.e.j.s.Server Started @1995566ms
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60096}
   [junit4]   2> 1995492 ERROR (jetty-launcher-15553-thread-2) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter Using logger factory 
org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.7.0
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-12-24T05:22:46.886918Z
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4d2b10a7{HTTP/1.1,[http/1.1]}{127.0.0.1:60097}
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.e.j.s.Server Started @1995566ms
   [junit4]   2> 1995492 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60097}
   [junit4]   2> 1995497 ERROR (jetty-launcher-15553-thread-1) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1995497 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter Using logger factory 
org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1995497 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.7.0
   [junit4]   2> 1995497 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1995497 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1995497 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-12-24T05:22:46.891591Z
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@6f6c7337{HTTP/1.1,[http/1.1]}{127.0.0.1:60098}
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.e.j.s.Server Started @1995571ms
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=60098}
   [junit4]   2> 1995498 ERROR (jetty-launcher-15553-thread-3) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter Using logger factory 
org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.7.0
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 1995498 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1995499 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-12-24T05:22:46.892998Z
   [junit4]   2> 1995503 INFO  (zkConnectionManagerCallback-15555-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995513 INFO  (zkConnectionManagerCallback-15559-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995514 INFO  (zkConnectionManagerCallback-15557-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995514 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1995514 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1995514 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 1995659 INFO  (jetty-launcher-15553-thread-2) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60091/solr
   [junit4]   2> 1995660 INFO  (jetty-launcher-15553-thread-3) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60091/solr
   [junit4]   2> 1995661 INFO  (zkConnectionManagerCallback-15564-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995662 INFO  (zkConnectionManagerCallback-15567-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995675 INFO  (zkConnectionManagerCallback-15569-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995675 INFO  (zkConnectionManagerCallback-15571-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995965 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.OverseerElectionContext I am going to be 
the leader 127.0.0.1:60098_solr
   [junit4]   2> 1995969 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.Overseer Overseer 
(id=72095672413192200-127.0.0.1:60098_solr-n_0000000000) starting
   [junit4]   2> 1995993 INFO  (zkConnectionManagerCallback-15580-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1995994 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60096_solr
   [junit4]   2> 1995996 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (1)
   [junit4]   2> 1995996 INFO  (zkCallback-15568-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1995996 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 1996001 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster 
at 127.0.0.1:60091/solr ready
   [junit4]   2> 1996002 INFO  
(OverseerStateUpdate-72095672413192200-127.0.0.1:60098_solr-n_0000000000) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.Overseer Starting to work on the main 
queue : 127.0.0.1:60098_solr
   [junit4]   2> 1996006 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.ZkController Publish 
node=127.0.0.1:60098_solr as DOWN
   [junit4]   2> 1996009 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating 
transient cache for 2147483647 transient cores
   [junit4]   2> 1996009 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60098_solr
   [junit4]   2> 1996031 INFO  (zkCallback-15568-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1996036 INFO  (jetty-launcher-15553-thread-1) [    ] 
o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:60091/solr
   [junit4]   2> 1996043 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1996043 INFO  (zkCallback-15579-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
   [junit4]   2> 1996070 INFO  (zkConnectionManagerCallback-15584-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1996082 INFO  (zkConnectionManagerCallback-15586-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1996096 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1996111 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system 
collection, keeping metrics history in memory.
   [junit4]   2> 1996116 INFO  (zkConnectionManagerCallback-15593-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1996125 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (2)
   [junit4]   2> 1996129 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.ZkController Publish 
node=127.0.0.1:60097_solr as DOWN
   [junit4]   2> 1996130 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster 
at 127.0.0.1:60091/solr ready
   [junit4]   2> 1996130 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system 
collection, keeping metrics history in memory.
   [junit4]   2> 1996145 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating 
transient cache for 2147483647 transient cores
   [junit4]   2> 1996146 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.ZkController Register node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60097_solr
   [junit4]   2> 1996154 INFO  (zkCallback-15579-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1996157 INFO  (zkCallback-15585-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1996157 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1996157 INFO  (zkCallback-15568-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1996158 INFO  (zkCallback-15592-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
   [junit4]   2> 1996218 INFO  (zkConnectionManagerCallback-15600-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1996220 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.c.ZkStateReader Updated live nodes from 
ZooKeeper... (0) -> (3)
   [junit4]   2> 1996220 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60098.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996222 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster 
at 127.0.0.1:60091/solr ready
   [junit4]   2> 1996222 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.h.a.MetricsHistoryHandler No .system 
collection, keeping metrics history in memory.
   [junit4]   2> 1996245 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60098.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996245 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60098.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996254 INFO  (jetty-launcher-15553-thread-3) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node3/.
   [junit4]   2> 1996261 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60096.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996292 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60097.solr.node' (registry 'solr.node') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996316 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60097.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996316 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60097.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996317 INFO  (jetty-launcher-15553-thread-1) 
[n:127.0.0.1:60097_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node1/.
   [junit4]   2> 1996326 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60096.solr.jvm' (registry 'solr.jvm') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996326 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60096.solr.jetty' (registry 'solr.jetty') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1996328 INFO  (jetty-launcher-15553-thread-2) 
[n:127.0.0.1:60096_solr    ] o.a.s.c.CorePropertiesLocator Found 0 core 
definitions underneath 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node2/.
   [junit4]   2> 1996404 INFO  (zkConnectionManagerCallback-15606-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1996410 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
   [junit4]   2> 1996411 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:60091/solr 
ready
   [junit4]   2> 1996414 INFO  (zkConnectionManagerCallback-15608-thread-1) [   
 ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 1998039 INFO  (qtp1702366203-40575) [n:127.0.0.1:60098_solr    
] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params 
collection.configName=conf1&maxShardsPerNode=1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2
 and sendToOCPQueue=true
   [junit4]   2> 1998044 INFO  
(OverseerThreadFactory-13283-thread-1-processing-n:127.0.0.1:60098_solr) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.a.c.CreateCollectionCmd Create collection 
collection1
   [junit4]   2> 1998164 INFO  (qtp1702366203-40577) [n:127.0.0.1:60098_solr    
] 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> 1998165 INFO  (qtp1702366203-40578) [n:127.0.0.1:60098_solr    
] 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> 1998167 INFO  (qtp1702366203-40579) [n:127.0.0.1:60098_solr    
] 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> 1998168 INFO  (qtp1702366203-40574) [n:127.0.0.1:60098_solr    
] 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> 1998169 INFO  (qtp1702366203-40576) [n:127.0.0.1:60098_solr    
] 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> 1998172 INFO  (qtp2131180892-40558) [n:127.0.0.1:60097_solr    
] 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> 1998193 INFO  (qtp2131180892-40559) [n:127.0.0.1:60097_solr    
] 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> 1998194 INFO  (qtp2131180892-40560) [n:127.0.0.1:60097_solr    
] 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> 1998196 INFO  (qtp2131180892-40561) [n:127.0.0.1:60097_solr    
] 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> 1998197 INFO  (qtp2131180892-40562) [n:127.0.0.1:60097_solr    
] 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> 1998199 INFO  (qtp971884143-40566) [n:127.0.0.1:60096_solr    
] 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> 1998200 INFO  (qtp971884143-40567) [n:127.0.0.1:60096_solr    
] 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> 1998201 INFO  (qtp971884143-40568) [n:127.0.0.1:60096_solr    
] 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> 1998202 INFO  (qtp971884143-40569) [n:127.0.0.1:60096_solr    
] 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> 1998203 INFO  (qtp971884143-40570) [n:127.0.0.1:60096_solr    
] 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> 1998224 INFO  
(OverseerStateUpdate-72095672413192200-127.0.0.1:60098_solr-n_0000000000) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "core":"collection1_shard1_replica_n1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:60096/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1998229 INFO  
(OverseerStateUpdate-72095672413192200-127.0.0.1:60098_solr-n_0000000000) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "core":"collection1_shard2_replica_n2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "base_url":"http://127.0.0.1:60097/solr";,
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 1998437 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr    
x:collection1_shard2_replica_n2] o.a.s.h.a.CoreAdminOperation core create 
command 
qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=collection1_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1998439 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr    
x:collection1_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create 
command 
qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 1998439 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr    
x:collection1_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault 
Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 1999484 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.7.0
   [junit4]   2> 1999484 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.7.0
   [junit4]   2> 1999522 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.IndexSchema [collection1_shard1_replica_n1] Schema name=test
   [junit4]   2> 1999530 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.s.IndexSchema [collection1_shard2_replica_n2] Schema name=test
   [junit4]   2> 1999651 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1999662 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1999705 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n2' using 
configuration from collection collection1, trusted=true
   [junit4]   2> 1999706 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60097.solr.core.collection1.shard2.replica_n2' (registry 
'solr.core.collection1.shard2.replica_n2') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1999706 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.SolrCore [[collection1_shard2_replica_n2] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node1/collection1_shard2_replica_n2],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node1/./collection1_shard2_replica_n2/data/]
   [junit4]   2> 1999711 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=36, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=19.9091796875, 
floorSegmentMB=1.359375, forceMergeDeletesPctAllowed=23.09469479140049, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0, 
deletesPctAllowed=41.173830503291896
   [junit4]   2> 1999712 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using 
configuration from collection collection1, trusted=true
   [junit4]   2> 1999713 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr_60096.solr.core.collection1.shard1.replica_n1' (registry 
'solr.core.collection1.shard1.replica_n1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5abf86d6
   [junit4]   2> 1999713 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SolrCore [[collection1_shard1_replica_n1] ] Opening new SolrCore at 
[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node2/collection1_shard1_replica_n1],
 
dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001/tempDir-001/node2/./collection1_shard1_replica_n1/data/]
   [junit4]   2> 1999716 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=36, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=19.9091796875, 
floorSegmentMB=1.359375, forceMergeDeletesPctAllowed=23.09469479140049, 
segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0, 
deletesPctAllowed=41.173830503291896
   [junit4]   2> 1999872 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1999872 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1999882 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1999882 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1999884 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1999884 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1999887 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=29, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.43869898333656443]
   [junit4]   2> 1999887 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@3fdaf821[collection1_shard1_replica_n1] main]
   [junit4]   2> 1999890 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1999890 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1999893 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 1999898 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=29, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.43869898333656443]
   [junit4]   2> 1999898 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.s.SolrIndexSearcher Opening 
[Searcher@28187461[collection1_shard2_replica_n2] main]
   [junit4]   2> 1999901 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 2000244 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2000349 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2000668 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 2000668 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1620709445008883712
   [junit4]   2> 2000674 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 2000674 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1620709445015175168
   [junit4]   2> 2000686 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: default
   [junit4]   2> 2000686 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: default
   [junit4]   2> 2000699 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ZkShardTerms Successful update of terms at 
/collections/collection1/terms/shard1 to Terms{values={core_node3=0}, version=0}
   [junit4]   2> 2000699 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContextBase make sure parent is created 
/collections/collection1/leaders/shard1
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: direct
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: direct
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: wordbreak
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: wordbreak
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: multipleFields
   [junit4]   2> 2000701 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: multipleFields
   [junit4]   2> 2000703 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ZkShardTerms Successful update of terms at 
/collections/collection1/terms/shard2 to Terms{values={core_node4=0}, version=0}
   [junit4]   2> 2000703 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContextBase make sure parent is created 
/collections/collection1/leaders/shard2
   [junit4]   2> 2000707 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2000708 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2000708 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:60096/solr/collection1_shard1_replica_n1/
   [junit4]   2> 2000708 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 2000715 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: jarowinkler
   [junit4]   2> 2000715 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: jarowinkler
   [junit4]   2> 2000715 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.SyncStrategy http://127.0.0.1:60096/solr/collection1_shard1_replica_n1/ 
has no replicas
   [junit4]   2> 2000715 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 2000716 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node 
/collections/collection1/leaders/shard1/leader after winning as 
/collections/collection1/leader_elect/shard1/election/72095672413192201-core_node3-n_0000000000
   [junit4]   2> 2000719 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 2000720 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 2000720 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.SyncStrategy Sync replicas to 
http://127.0.0.1:60097/solr/collection1_shard2_replica_n2/
   [junit4]   2> 2000721 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 2000722 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.SyncStrategy http://127.0.0.1:60097/solr/collection1_shard2_replica_n2/ 
has no replicas
   [junit4]   2> 2000722 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContext Found all replicas participating in 
election, clear LIR
   [junit4]   2> 2000722 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:60096/solr/collection1_shard1_replica_n1/ shard1
   [junit4]   2> 2000723 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node 
/collections/collection1/leaders/shard2/leader after winning as 
/collections/collection1/leader_elect/shard2/election/72095672413192204-core_node4-n_0000000000
   [junit4]   2> 2000733 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: external
   [junit4]   2> 2000733 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: external
   [junit4]   2> 2000736 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2000737 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ShardLeaderElectionContext I am the new leader: 
http://127.0.0.1:60097/solr/collection1_shard2_replica_n2/ shard2
   [junit4]   2> 2000738 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ZkController No registered searcher found for core: 
collection1_shard1_replica_n1, waiting until a searcher is registered before 
publishing as active
   [junit4]   2> 2000740 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: freq
   [junit4]   2> 2000742 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: freq
   [junit4]   2> 2000742 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: fqcn
   [junit4]   2> 2000744 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: fqcn
   [junit4]   2> 2000746 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: perDict
   [junit4]   2> 2000748 INFO  
(searcherExecutor-13300-thread-1-processing-n:127.0.0.1:60096_solr 
x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node3) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.c.SolrCore 
[collection1_shard1_replica_n1] Registered new searcher 
Searcher@3fdaf821[collection1_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2000748 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.h.c.SpellCheckComponent Loading spell 
index for spellchecker: perDict
   [junit4]   2> 2000749 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.ZkController Found a registered searcher: 
Searcher@3fdaf821[collection1_shard1_replica_n1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}, took: 10.0 ms for 
core: collection1_shard1_replica_n1, id: org.apache.solr.core.SolrCore@170cc73
   [junit4]   2> 2000750 INFO  
(searcherExecutor-13299-thread-1-processing-n:127.0.0.1:60097_solr 
x:collection1_shard2_replica_n2 c:collection1 s:shard2 r:core_node4) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.c.SolrCore 
[collection1_shard2_replica_n2] Registered new searcher 
Searcher@28187461[collection1_shard2_replica_n2] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2000757 INFO  (qtp971884143-40565) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf1&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2318
   [junit4]   2> 2000862 INFO  (zkCallback-15585-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000862 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000862 INFO  (zkCallback-15570-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000866 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 2000868 INFO  (qtp2131180892-40557) [n:127.0.0.1:60097_solr 
c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica_n2] 
o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores 
params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&newCollection=true&name=collection1_shard2_replica_n2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT}
 status=0 QTime=2431
   [junit4]   2> 2000871 INFO  (qtp1702366203-40575) [n:127.0.0.1:60098_solr    
] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 
45 seconds. Check all shard replicas
   [junit4]   2> 2000969 INFO  (zkCallback-15568-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000969 INFO  (zkCallback-15585-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000969 INFO  (zkCallback-15585-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000971 INFO  (qtp1702366203-40575) [n:127.0.0.1:60098_solr    
] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections 
params={collection.configName=conf1&maxShardsPerNode=1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2}
 status=0 QTime=2931
   [junit4]   2> 2000971 INFO  (zkCallback-15570-thread-2) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000971 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent 
state:SyncConnected type:NodeDataChanged 
path:/collections/collection1/state.json] for collection [collection1] has 
occurred - updating... (live nodes size: [3])
   [junit4]   2> 2000976 ERROR (qtp971884143-40566) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: no servers 
hosting shard: shard2
   [junit4]   2>        at 
org.apache.solr.handler.component.HttpShardHandler.prepDistributed(HttpShardHandler.java:436)
   [junit4]   2>        at 
org.apache.solr.handler.component.SearchHandler.getAndPrepShardHandler(SearchHandler.java:226)
   [junit4]   2>        at 
org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:267)
   [junit4]   2>        at 
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:199)
   [junit4]   2>        at 
org.apache.solr.core.SolrCore.execute(SolrCore.java:2551)
   [junit4]   2>        at 
org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:709)
   [junit4]   2>        at 
org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:515)
   [junit4]   2>        at 
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:395)
   [junit4]   2>        at 
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:341)
   [junit4]   2>        at 
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
   [junit4]   2>        at 
org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:158)
   [junit4]   2>        at 
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610)
   [junit4]   2>        at 
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
   [junit4]   2>        at 
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1588)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203)
   [junit4]   2>        at 
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480)
   [junit4]   2>        at 
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1557)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:753)
   [junit4]   2>        at 
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132)
   [junit4]   2>        at 
org.eclipse.jetty.server.Server.handle(Server.java:502)
   [junit4]   2>        at 
org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364)
   [junit4]   2>        at 
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260)
   [junit4]   2>        at 
org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305)
   [junit4]   2>        at 
org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
   [junit4]   2>        at 
org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
   [junit4]   2>        at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765)
   [junit4]   2>        at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683)
   [junit4]   2>        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]   2> 
   [junit4]   2> 2000976 INFO  (qtp971884143-40566) [n:127.0.0.1:60096_solr 
c:collection1 s:shard1 r:core_node3 x:collection1_shard1_replica_n1] 
o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/select 
params={q=cat:football^2} status=503 QTime=0
   [junit4]   2> 2000980 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1328011927
   [junit4]   2> 2000980 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60098_solr
   [junit4]   2> 2000980 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=488050176
   [junit4]   2> 2000980 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60097_solr
   [junit4]   2> 2000981 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 2000981 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.c.ZkController Publish node=127.0.0.1:60098_solr as DOWN
   [junit4]   2> 2000981 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 2000981 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.c.ZkController Publish node=127.0.0.1:60097_solr as DOWN
   [junit4]   2> 2000982 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=110489012
   [junit4]   2> 2000982 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.c.ZkController Remove node as live in 
ZooKeeper:/live_nodes/127.0.0.1:60096_solr
   [junit4]   2> 2000985 INFO  (coreCloseExecutor-13310-thread-1) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.c.SolrCore 
[collection1_shard2_replica_n2]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@27e96c5f
   [junit4]   2> 2000985 INFO  (coreCloseExecutor-13310-thread-1) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.core.collection1.shard2.replica_n2, tag=27e96c5f
   [junit4]   2> 2000985 INFO  (coreCloseExecutor-13310-thread-1) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@4fc0b12c: rootName = 
solr_60097, domain = solr.core.collection1.shard2.replica_n2, service url = 
null, agent id = null] for registry solr.core.collection1.shard2.replica_n2 / 
com.codahale.metrics.MetricRegistry@3088fb7a
   [junit4]   2> 2000986 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 2000986 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@22aa21db: rootName = 
solr_60098, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@1aa4f3fe
   [junit4]   2> 2000989 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.c.CoreContainer Publish this node as DOWN...
   [junit4]   2> 2000989 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.c.ZkController Publish node=127.0.0.1:60096_solr as DOWN
   [junit4]   2> 2001002 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 2001002 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@265bbc3e: rootName = 
solr_60098, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@5a7d4578
   [junit4]   2> 2001009 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 2001009 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@7d2b00dc: rootName = 
solr_60098, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@17b72cfa
   [junit4]   2> 2001009 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 2001010 INFO  (closeThreadPool-15616-thread-2) [    ] 
o.a.s.c.Overseer Overseer 
(id=72095672413192200-127.0.0.1:60098_solr-n_0000000000) closing
   [junit4]   2> 2001013 INFO  
(OverseerStateUpdate-72095672413192200-127.0.0.1:60098_solr-n_0000000000) 
[n:127.0.0.1:60098_solr    ] o.a.s.c.Overseer Overseer Loop exiting : 
127.0.0.1:60098_solr
   [junit4]   2> 2001016 INFO  
(OverseerAutoScalingTriggerThread-72095672413192200-127.0.0.1:60098_solr-n_0000000000)
 [    ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we 
are closed, exiting.
   [junit4]   2> 2001018 INFO  (closeThreadPool-15616-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=72095672413192200-127.0.0.1:60098_solr-n_0000000000) closing
   [junit4]   2> 2001018 INFO  (coreCloseExecutor-13310-thread-1) 
[n:127.0.0.1:60097_solr c:collection1 s:shard2 r:core_node4 
x:collection1_shard2_replica_n2] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard2.leader, tag=27e96c5f
   [junit4]   2> 2001019 INFO  (jetty-closer-15609-thread-1) [    ] 
o.a.s.c.Overseer Overseer 
(id=72095672413192200-127.0.0.1:60098_solr-n_0000000000) closing
   [junit4]   2> 2001023 INFO  (zkCallback-15599-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 2001024 INFO  (zkCallback-15592-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 2001024 INFO  (zkCallback-15585-thread-2) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 2001024 INFO  (jetty-closer-15609-thread-1) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@6f6c7337{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 2001024 INFO  (jetty-closer-15609-thread-1) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@2656aa5c{/solr,null,UNAVAILABLE}
   [junit4]   2> 2001027 INFO  (jetty-closer-15609-thread-1) [    ] 
o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2001033 INFO  (coreCloseExecutor-13311-thread-1) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.c.SolrCore 
[collection1_shard1_replica_n1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@170cc73
   [junit4]   2> 2001033 INFO  (coreCloseExecutor-13311-thread-1) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.core.collection1.shard1.replica_n1, tag=170cc73
   [junit4]   2> 2001033 INFO  (coreCloseExecutor-13311-thread-1) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@22a76d0: rootName = 
solr_60096, domain = solr.core.collection1.shard1.replica_n1, service url = 
null, agent id = null] for registry solr.core.collection1.shard1.replica_n1 / 
com.codahale.metrics.MetricRegistry@46776e9c
   [junit4]   2> 2001034 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 2001034 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@756e807c: rootName = 
solr_60097, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@7a5148c3
   [junit4]   2> 2001036 INFO  (zkCallback-15570-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
   [junit4]   2> 2001036 INFO  (zkCallback-15570-thread-2) [    ] 
o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:60096_solr
   [junit4]   2> 2001040 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 2001040 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@55e165e2: rootName = 
solr_60097, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@5a7d4578
   [junit4]   2> 2001043 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 2001043 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@37c10e4: rootName = 
solr_60097, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@17b72cfa
   [junit4]   2> 2001043 INFO  (jetty-closer-15609-thread-2) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 2001047 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 
0x10022a1d008000e, likely client has closed socket
   [junit4]   2> 2001048 INFO  (coreCloseExecutor-13311-thread-1) 
[n:127.0.0.1:60096_solr c:collection1 s:shard1 r:core_node3 
x:collection1_shard1_replica_n1] o.a.s.m.SolrMetricManager Closing metric 
reporters for registry=solr.collection.collection1.shard1.leader, tag=170cc73
   [junit4]   2> 2001049 INFO  (jetty-closer-15609-thread-2) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@4d2b10a7{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 2001049 INFO  (zkCallback-15592-thread-1) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 2001049 INFO  (jetty-closer-15609-thread-2) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@69d9b7a5{/solr,null,UNAVAILABLE}
   [junit4]   2> 2001050 INFO  (jetty-closer-15609-thread-2) [    ] 
o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2001051 INFO  (zkCallback-15570-thread-2) [    ] 
o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
   [junit4]   2> 2001053 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 2001053 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@d58223: rootName = 
solr_60096, domain = solr.node, service url = null, agent id = null] for 
registry solr.node / com.codahale.metrics.MetricRegistry@78ce2537
   [junit4]   2> 2001058 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 2001059 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@6e5df9d0: rootName = 
solr_60096, domain = solr.jvm, service url = null, agent id = null] for 
registry solr.jvm / com.codahale.metrics.MetricRegistry@5a7d4578
   [junit4]   2> 2001062 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 2001062 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.r.SolrJmxReporter Closing reporter 
[org.apache.solr.metrics.reporters.SolrJmxReporter@4e95ed26: rootName = 
solr_60096, domain = solr.jetty, service url = null, agent id = null] for 
registry solr.jetty / com.codahale.metrics.MetricRegistry@17b72cfa
   [junit4]   2> 2001062 INFO  (jetty-closer-15609-thread-3) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, 
tag=null
   [junit4]   2> 2001066 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] 
o.a.z.s.NIOServerCnxn Unable to read additional data from client sessionid 
0x10022a1d008000d, likely client has closed socket
   [junit4]   2> 2001067 INFO  (jetty-closer-15609-thread-3) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@19fe87c6{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 2001068 INFO  (jetty-closer-15609-thread-3) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@752ddbf7{/solr,null,UNAVAILABLE}
   [junit4]   2> 2001068 INFO  (jetty-closer-15609-thread-3) [    ] 
o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2001073 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
   [junit4]   2> 2001079 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>        7       /solr/aliases.json
   [junit4]   2>        7       /solr/clusterprops.json
   [junit4]   2>        3       /solr/security.json
   [junit4]   2>        2       /solr/collections/collection1/terms/shard2
   [junit4]   2>        2       /solr/configs/conf1
   [junit4]   2>        2       /solr/collections/collection1/terms/shard1
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2>        9       /solr/collections/collection1/state.json
   [junit4]   2>        7       /solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2>        7       /solr/live_nodes
   [junit4]   2>        7       /solr/collections
   [junit4]   2> 
   [junit4]   2> 2001240 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:60091
   [junit4]   2> 2001240 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 60091
   [junit4]   2> 2001240 INFO  
(TEST-TestRequestForwarding.testMultiCollectionQuery-seed#[E2806E7B5D694F99]) [ 
   ] o.a.s.SolrTestCaseJ4 ###Ending testMultiCollectionQuery
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestRequestForwarding -Dtests.method=testMultiCollectionQuery 
-Dtests.seed=E2806E7B5D694F99 -Dtests.slow=true -Dtests.locale=ro-MD 
-Dtests.timezone=Europe/Tirane -Dtests.asserts=true 
-Dtests.file.encoding=US-ASCII
   [junit4] ERROR   5.94s J1 | TestRequestForwarding.testMultiCollectionQuery 
<<<
   [junit4]    > Throwable #1: java.lang.RuntimeException: Query 
'q=cat%3Afootball%5E2' failed, 
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([E2806E7B5D694F99:F3F3A94A811F4AE5]:0)
   [junit4]    >        at 
org.apache.solr.cloud.TestRequestForwarding.testMultiCollectionQuery(TestRequestForwarding.java:67)
   [junit4]    >        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]    >        at 
java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
   [junit4]    >        at 
java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]    >        at 
java.base/java.lang.reflect.Method.invoke(Method.java:564)
   [junit4]    >        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4]    > Caused by: java.io.IOException: Server returned HTTP response 
code: 503 for URL: 
http://127.0.0.1:60098/solr/collection1/select?q=cat%3Afootball%5E2
   [junit4]    >        at 
java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream0(HttpURLConnection.java:1895)
   [junit4]    >        at 
java.base/sun.net.www.protocol.http.HttpURLConnection.getInputStream(HttpURLConnection.java:1491)
   [junit4]    >        at java.base/java.net.URL.openStream(URL.java:1117)
   [junit4]    >        at 
org.apache.solr.cloud.TestRequestForwarding.testMultiCollectionQuery(TestRequestForwarding.java:65)
   [junit4]    >        ... 38 more
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.TestRequestForwarding_E2806E7B5D694F99-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {}, 
docValues:{}, maxPointsInLeafNode=1960, maxMBSortInHeap=7.268239111217935, 
sim=RandomSimilarity(queryNorm=false): {}, locale=ro-MD, timezone=Europe/Tirane
   [junit4]   2> NOTE: Mac OS X 10.11.6 x86_64/Oracle Corporation 9 
(64-bit)/cpus=3,threads=1,free=242325160,total=512753664
   [junit4]   2> NOTE: All tests run in this JVM: [TestIndexSearcher, 
ZkSolrClientTest, SharedFSAutoReplicaFailoverTest, BasicDistributedZk2Test, 
DistributedQueryComponentOptimizationTest, PathHierarchyTokenizerFactoryTest, 
MinimalSchemaTest, SolrTestCaseJ4Test, TestReqParamsAPI, 
BigEndianAscendingWordDeserializerTest, TestIBSimilarityFactory, 
RangeFacetCloudTest, MetricUtilsTest, HttpSolrCallGetCoreTest, 
TestSkipOverseerOperations, AddReplicaTest, CollectionReloadTest, 
TestSubQueryTransformerDistrib, SuggesterFSTTest, VersionInfoTest, 
BlockCacheTest, TestCollationFieldDocValues, 
SignatureUpdateProcessorFactoryTest, RequestLoggingTest, TestSmileRequest, 
TestSolrCloudWithHadoopAuthPlugin, CircularListTest, TestSafeXMLParsing, 
TestDocSet, PeerSyncTest, TestBackupRepositoryFactory, CursorPagingTest, 
TestHighlightDedupGrouping, TestSolrCloudWithKerberosAlt, 
TestSchemaNameResource, UninvertDocValuesMergePolicyTest, 
TestPerFieldSimilarity, JSONWriterTest, TestManagedSchemaThreadSafety, 
CheckHdfsIndexTest, TestCharFilters, TestSchemaSimilarityResource, 
AnalyticsQueryTest, TestPseudoReturnFields, FullHLLTest, GraphQueryTest, 
FieldAnalysisRequestHandlerTest, UUIDFieldTest, TestSweetSpotSimilarityFactory, 
TestCoreBackup, SolrSlf4jReporterTest, TestSolrQueryParser, 
TestBlendedInfixSuggestions, TestDFISimilarityFactory, 
TestHighFrequencyDictionaryFactory, ComputePlanActionTest, 
PeerSyncWithLeaderTest, HdfsRecoverLeaseTest, TestNumericRangeQuery32, 
TestSearcherReuse, TestDocumentBuilder, TestPointFields, 
TestFieldCacheWithThreads, OverseerTest, BitVectorTest, 
TestHttpShardHandlerFactory, BJQParserTest, 
TestCollectionsAPIViaSolrCloudCluster, ShardRoutingCustomTest, 
TestSerializedLuceneMatchVersion, SortSpecParsingTest, TestFreeTextSuggestions, 
TestObjectReleaseTracker, TestFieldSortValues, TestReloadDeadlock, 
TestNamedUpdateProcessors, CollectionsAPISolrJTest, SuggesterTest, 
DistribCursorPagingTest, TestTolerantUpdateProcessorCloud, 
TestInPlaceUpdatesDistrib, SynonymTokenizerTest, TestCloudInspectUtil, 
TestManagedStopFilterFactory, CollectionPropsTest, URLClassifyProcessorTest, 
TestInfoStreamLogging, TestStandardQParsers, CdcrVersionReplicationTest, 
TestDirectoryFactory, RecoveryAfterSoftCommitTest, FileBasedSpellCheckerTest, 
ConjunctionSolrSpellCheckerTest, TestQuerySenderListener, 
TimeRoutedAliasUpdateProcessorTest, NodeMutatorTest, TestCustomDocTransformer, 
TestConfigsApi, CloudMLTQParserTest, TestReversedWildcardFilterFactory, 
TestSimpleTextCodec, CreateCollectionCleanupTest, TestSimExecutePlanAction, 
MultiSolrCloudTestCaseTest, TestCursorMarkWithoutUniqueKey, 
PropertiesRequestHandlerTest, TestMissingGroups, TermVectorComponentTest, 
TestNumericTerms32, BlobRepositoryCloudTest, TestClusterProperties, 
TestComplexPhraseLeadingWildcard, HttpPartitionOnCommitTest, 
RestartWhileUpdatingTest, AtomicUpdateProcessorFactoryTest, 
TestPayloadCheckQParserPlugin, LeaderVoteWaitTimeoutTest, 
SolrCmdDistributorTest, SimpleCollectionCreateDeleteTest, 
TestShortCircuitedRequests, ManagedSchemaRoundRobinCloudTest, 
TestFieldTypeCollectionResource, ConfigureRecoveryStrategyTest, 
CollectionsAPIAsyncDistributedZkTest, ImplicitSnitchTest, TokenizerChainTest, 
XsltUpdateRequestHandlerTest, TestSolrFieldCacheBean, 
AutoAddReplicasPlanActionTest, TestDownShardTolerantSearch, 
TestBulkSchemaConcurrent, RAMDirectoryFactoryTest, SortByFunctionTest, 
RandomizedTaggerTest, SSLMigrationTest, TestSuggestSpellingConverter, 
TestOnReconnectListenerSupport, DateRangeFieldTest, BasicZkTest, 
TestConfigSetsAPIExclusivity, BufferStoreTest, CacheHeaderTest, 
PrimitiveFieldTypeTest, TestUtilizeNode, HdfsCollectionsAPIDistributedZkTest, 
SolrShardReporterTest, DistributedTermsComponentTest, NodeLostTriggerTest, 
TestLMJelinekMercerSimilarityFactory, RegexBoostProcessorTest, TestSQLHandler, 
DistributedSpellCheckComponentTest, OpenExchangeRatesOrgProviderTest, 
AnalysisErrorHandlingTest, TestUninvertingReader, TestDelegationWithHadoopAuth, 
TestRandomCollapseQParserPlugin, DistributedFacetPivotLongTailTest, 
RegexBytesRefFilterTest, TestJsonFacetsStatsParsing, 
ZookeeperStatusHandlerTest, LeaderElectionTest, RemoteQueryErrorTest, 
TestManagedResourceStorage, DefaultValueUpdateProcessorTest, 
TestStressCloudBlindAtomicUpdates, TestUseDocValuesAsStored, 
DistributedFacetPivotSmallTest, HdfsRestartWhileUpdatingTest, 
TestNumericTokenStream, SystemLogListenerTest, QueryParsingTest, 
DistributedMLTComponentTest, InfixSuggestersTest, XmlInterpolationTest, 
DirectoryFactoryTest, TestAddFieldRealTimeGet, TestUnInvertedFieldException, 
TestQueryUtils, TestRemoteStreaming, JvmMetricsTest, TestJsonFacetRefinement, 
TestSimpleTrackingShardHandler, TestNoOpRegenerator, ResponseLogComponentTest, 
CleanupOldIndexTest, TestXIncludeConfig, TestLFUCache, 
AutoscalingHistoryHandlerTest, TestGraphTermsQParserPlugin, 
DistributedIntervalFacetingTest, TestBulkSchemaAPI, 
AssignBackwardCompatibilityTest, SuggestComponentTest, 
ShufflingReplicaListTransformerTest, DocExpirationUpdateProcessorFactoryTest, 
OverseerStatusTest, TestCloudJSONFacetJoinDomain, EnumFieldTest, 
QueryElevationComponentTest, LIROnShardRestartTest, CursorMarkTest, 
TestSchemalessBufferedUpdates, TestValueSourceCache, 
AnalysisAfterCoreReloadTest, BasicFunctionalityTest, OutputWriterTest, 
SampleTest, TestDistributedGrouping, TestDistributedMissingSort, TestJoin, 
TestRandomDVFaceting, TestSolrCoreProperties, TestTolerantSearch, 
TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, 
TestEmbeddedSolrServerConstructors, TestEmbeddedSolrServerSchemaAPI, 
TestJettySolrRunner, ConnectionReuseTest, ChaosMonkeyNothingIsSafeTest, 
ChaosMonkeyNothingIsSafeWithPullReplicasTest, ChaosMonkeySafeLeaderTest, 
ChaosMonkeySafeLeaderWithPullReplicasTest, CloudExitableDirectoryReaderTest, 
ClusterStateTest, ConcurrentCreateRoutedAliasTest, ConfigSetsAPITest, 
CreateRoutedAliasTest, DeleteInactiveReplicaTest, 
DeleteLastCustomShardedReplicaTest, DeleteNodeTest, DeleteReplicaTest, 
DeleteShardTest, DistribDocExpirationUpdateProcessorTest, 
DistribJoinFromCollectionTest, DistributedQueueTest, DocValuesNotIndexedTest, 
ForceLeaderTest, LIRRollingUpdatesTest, MissingSegmentRecoveryTest, 
MoveReplicaHDFSFailoverTest, MoveReplicaHDFSTest, 
OutOfBoxZkACLAndCredentialsProvidersTest, 
OverriddenZkACLAndCredentialsProvidersTest, 
OverseerCollectionConfigSetProcessorTest, ReplaceNodeNoTargetTest, 
ReplaceNodeTest, SolrXmlInZkTest, SplitShardTest, TestAuthenticationFramework, 
TestCloudConsistency, TestCloudPhrasesIdentificationComponent, 
TestCloudPivotFacet, TestCloudPseudoReturnFields, TestCloudRecovery, 
TestConfigSetsAPIZkFailure, TestDeleteCollectionOnDownNodes, 
TestDistribDocBasedVersion, TestExclusionRuleCollectionAccess, 
TestLeaderElectionWithEmptyReplica, TestPullReplica, 
TestPullReplicaErrorHandling, TestRandomRequestDistribution, 
TestRequestForwarding]
   [junit4] Completed [498/836 (1!)] on J1 in 6.65s, 1 test, 1 error <<< 
FAILURES!

[...truncated 43791 lines...]
[repro] Jenkins log URL: 
https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/988/consoleText

[repro] Revision: bcf1a4eaf8d3b945f11833c9dfed4a17a6d6ac58

[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line:  ant test  -Dtestcase=TestRequestForwarding 
-Dtests.method=testMultiCollectionQuery -Dtests.seed=E2806E7B5D694F99 
-Dtests.slow=true -Dtests.locale=ro-MD -Dtests.timezone=Europe/Tirane 
-Dtests.asserts=true -Dtests.file.encoding=US-ASCII

[repro] ant clean

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

[...truncated 3632 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 
-Dtests.class="*.TestRequestForwarding" -Dtests.showOutput=onerror 
"-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" 
-Dtests.seed=E2806E7B5D694F99 -Dtests.slow=true -Dtests.locale=ro-MD 
-Dtests.timezone=Europe/Tirane -Dtests.asserts=true 
-Dtests.file.encoding=US-ASCII

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

[...truncated 70 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to