You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2021/04/20 22:44:19 UTC

[JENKINS] Lucene » Lucene-Solr-Tests-8.x - Build # 2157 - Unstable!

Build: https://ci-builds.apache.org/job/Lucene/job/Lucene-Solr-Tests-8.x/2157/

1 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.servlet.HttpSolrCallGetCoreTest

Error Message:
Timeout occurred while waiting response from server at: http://127.0.0.1:40485/solr

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:40485/solr
	at __randomizedtesting.SeedInfo.seed([EA919446BA2ED35B]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:692)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:266)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
	at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:369)
	at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:297)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1171)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:934)
	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:866)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:214)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:231)
	at org.apache.solr.servlet.HttpSolrCallGetCoreTest.setupCluster(HttpSolrCallGetCoreTest.java:53)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:878)
	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.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
	at java.net.SocketInputStream.read(SocketInputStream.java:171)
	at java.net.SocketInputStream.read(SocketInputStream.java:141)
	at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
	at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
	at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
	at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
	at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:571)
	... 36 more




Build Log:
[...truncated 13933 lines...]
   [junit4] Suite: org.apache.solr.servlet.HttpSolrCallGetCoreTest
   [junit4]   2> 452680 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/server/solr/configsets/_default/conf'
   [junit4]   2> 452680 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 452681 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/data-dir-126-001
   [junit4]   2> 452681 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 452681 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
   [junit4]   2> 452681 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.SolrCloudTestCase Using per-replica state
   [junit4]   2> 452682 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001
   [junit4]   2> 452682 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 452686 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
   [junit4]   2> 452686 INFO  (ZkTestServer Run Thread) [     ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 452687 WARN  (ZkTestServer Run Thread) [     ] o.a.z.s.ServerCnxnFactory maxCnxns is not configured, using default value 0.
   [junit4]   2> 452786 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer start zk server on port: 38793
   [junit4]   2> 452786 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:38793
   [junit4]   2> 452786 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38793
   [junit4]   2> 452786 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38793
   [junit4]   2> 452788 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 452794 INFO  (zkConnectionManagerCallback-3347-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 452794 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 452797 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 452805 INFO  (zkConnectionManagerCallback-3349-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 452805 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 452806 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 452810 INFO  (zkConnectionManagerCallback-3351-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 452810 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 452811 WARN  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker-SendThread(127.0.0.1:38793)) [     ] o.a.z.ClientCnxn An exception was thrown while closing send thread for session 0x104a83241d90002.
   [junit4]   2>           => EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90002, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77)
   [junit4]   2> org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90002, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1275) [zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 452913 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 452913 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
   [junit4]   2> 452913 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.Server jetty-9.4.34.v20201102; built: 2020-11-02T14:15:39.302Z; git: e46af88704a893fc12cb0e3bf46e2c7b48a009e7; jvm 1.8.0_281-b09
   [junit4]   2> 452914 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 452914 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 452914 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6d1c63c9{/solr,null,AVAILABLE}
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.AbstractConnector Started ServerConnector@1ff846a8{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:40485}
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.e.j.s.Server Started @452949ms
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, zkHost=127.0.0.1:38793/solr, hostPort=40485}
   [junit4]   2> 452917 ERROR (jetty-launcher-3352-thread-1) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.9.0
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in cloud mode on port null
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr
   [junit4]   2> 452917 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2021-04-20T21:52:21.889Z
   [junit4]   2> 452919 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 452922 INFO  (zkConnectionManagerCallback-3354-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 452922 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 452923 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
   [junit4]   2> 452926 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.SolrXmlConfig Metrics collection is disabled.
   [junit4]   2> 452927 WARN  (jetty-launcher-3352-thread-1-SendThread(127.0.0.1:38793)) [     ] o.a.z.ClientCnxn An exception was thrown while closing send thread for session 0x104a83241d90003.
   [junit4]   2>           => EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90003, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77)
   [junit4]   2> org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90003, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1275) [zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 453613 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
   [junit4]   2> 453613 WARN  (jetty-launcher-3352-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7cd6746e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 453613 WARN  (jetty-launcher-3352-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7cd6746e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 453616 WARN  (jetty-launcher-3352-thread-1) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@49c74b1e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 453617 WARN  (jetty-launcher-3352-thread-1) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@49c74b1e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 453618 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38793/solr
   [junit4]   2> 453619 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 453622 INFO  (zkConnectionManagerCallback-3365-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 453622 INFO  (jetty-launcher-3352-thread-1) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 453724 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 453726 INFO  (zkConnectionManagerCallback-3367-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 453726 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 453806 WARN  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.ZkController Contents of zookeeper /security.json are world-readable; consider setting up ACLs as described in https://solr.apache.org/guide/zookeeper-access-control.html
   [junit4]   2> 453810 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:40485_solr
   [junit4]   2> 453811 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.Overseer Overseer (id=73368427751342085-127.0.0.1:40485_solr-n_0000000000) starting
   [junit4]   2> 453816 INFO  (OverseerStateUpdate-73368427751342085-127.0.0.1:40485_solr-n_0000000000) [n:127.0.0.1:40485_solr     ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:40485_solr
   [junit4]   2> 453817 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40485_solr
   [junit4]   2> 453820 INFO  (OverseerStateUpdate-73368427751342085-127.0.0.1:40485_solr-n_0000000000) [n:127.0.0.1:40485_solr     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 453821 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.p.PackageLoader /packages.json updated to version -1
   [junit4]   2> 453821 WARN  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.CoreContainer Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info
   [junit4]   2> 453839 INFO  (jetty-launcher-3352-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1
   [junit4]   2> 453853 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=1
   [junit4]   2> 453853 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 453856 INFO  (zkConnectionManagerCallback-3382-thread-1) [     ] o.a.s.c.c.ConnectionManager zkClient has connected
   [junit4]   2> 453856 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 453860 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
   [junit4]   2> 453862 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38793/solr ready
   [junit4]   2> 453870 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1
   [junit4]   2> 453878 WARN  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection collection1 is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
   [junit4]   2> 453881 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard1_replica_n1",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453885 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard1_replica_n3",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453887 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard2_replica_n5",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453890 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard2_replica_n7",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard2",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453893 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard3_replica_n9",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard3",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453895 INFO  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.o.SliceMutator createReplica() {
   [junit4]   2>   "core":"collection1_shard3_replica_n11",
   [junit4]   2>   "node_name":"127.0.0.1:40485_solr",
   [junit4]   2>   "base_url":"http://127.0.0.1:40485/solr",
   [junit4]   2>   "collection":"collection1",
   [junit4]   2>   "shard":"shard3",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "type":"NRT",
   [junit4]   2>   "operation":"ADDREPLICA",
   [junit4]   2>   "waitForFinalState":"false"} 
   [junit4]   2> 453901 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr    x:collection1_shard1_replica_n3 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=config&newCollection=true&name=collection1_shard1_replica_n3&action=CREATE&numShards=3&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453901 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr    x:collection1_shard2_replica_n7 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node8&collection.configName=config&newCollection=true&name=collection1_shard2_replica_n7&action=CREATE&numShards=3&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453901 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr    x:collection1_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=config&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=3&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453901 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr    x:collection1_shard1_replica_n3 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
   [junit4]   2> 453901 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr    x:collection1_shard2_replica_n5 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=config&newCollection=true&name=collection1_shard2_replica_n5&action=CREATE&numShards=3&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453902 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr    x:collection1_shard3_replica_n9 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node10&collection.configName=config&newCollection=true&name=collection1_shard3_replica_n9&action=CREATE&numShards=3&collection=collection1&shard=shard3&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453903 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr    x:collection1_shard3_replica_n11 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node12&collection.configName=config&newCollection=true&name=collection1_shard3_replica_n11&action=CREATE&numShards=3&collection=collection1&shard=shard3&wt=javabin&version=2&replicaType=NRT
   [junit4]   2> 453948 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453950 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453951 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453953 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453976 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 453976 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 453977 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard3_replica_n9' using configuration from configset config, trusted=true
   [junit4]   2> 453977 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 453977 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SolrCore [[collection1_shard3_replica_n9] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard3_replica_n9], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard3_replica_n9/data/]
   [junit4]   2> 453978 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 453978 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n7' using configuration from configset config, trusted=true
   [junit4]   2> 453978 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 453980 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SolrCore [[collection1_shard2_replica_n7] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard2_replica_n7], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard2_replica_n7/data/]
   [junit4]   2> 453981 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 453981 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica_n5' using configuration from configset config, trusted=true
   [junit4]   2> 453982 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SolrCore [[collection1_shard2_replica_n5] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard2_replica_n5], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard2_replica_n5/data/]
   [junit4]   2> 453982 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 453982 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453983 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 453983 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n1' using configuration from configset config, trusted=true
   [junit4]   2> 453983 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [[collection1_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard1_replica_n1/data/]
   [junit4]   2> 453995 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 453995 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 453995 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 453995 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica_n3' using configuration from configset config, trusted=true
   [junit4]   2> 453995 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SolrCore [[collection1_shard1_replica_n3] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard1_replica_n3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard1_replica_n3/data/]
   [junit4]   2> 454015 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.s.IndexSchema Schema name=minimal
   [junit4]   2> 454016 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
   [junit4]   2> 454016 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard3_replica_n11' using configuration from configset config, trusted=true
   [junit4]   2> 454016 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.SolrCore [[collection1_shard3_replica_n11] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard3_replica_n11], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J3/temp/solr.servlet.HttpSolrCallGetCoreTest_EA919446BA2ED35B-001/tempDir-001/node1/collection1_shard3_replica_n11/data/]
   [junit4]   2> 454070 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454071 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454075 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454075 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454077 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454079 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454079 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454079 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927510245376
   [junit4]   2> 454082 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454082 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454083 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454083 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454084 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454084 INFO  (searcherExecutor-3384-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard3_replica_n9 c:collection1 s:shard3 r:core_node10) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SolrCore [collection1_shard3_replica_n9]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454084 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454085 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454085 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927516536832
   [junit4]   2> 454091 INFO  (searcherExecutor-3392-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard1_replica_n3 c:collection1 s:shard1 r:core_node4) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SolrCore [collection1_shard1_replica_n3]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454098 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard1 to Terms{values={core_node4=0}, version=0}
   [junit4]   2> 454098 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard1
   [junit4]   2> 454098 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454098 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454099 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454099 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454101 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454101 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454102 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454102 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454103 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454104 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454104 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard3 to Terms{values={core_node10=0}, version=0}
   [junit4]   2> 454104 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard3
   [junit4]   2> 454104 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454104 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454104 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454104 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454104 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927536459776
   [junit4]   2> 454105 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927537508352
   [junit4]   2> 454106 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454106 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454107 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454107 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454107 INFO  (searcherExecutor-3390-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node2) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrCore [collection1_shard1_replica_n1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454109 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454109 INFO  (searcherExecutor-3394-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard3_replica_n11 c:collection1 s:shard3 r:core_node12) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.SolrCore [collection1_shard3_replica_n11]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454109 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454109 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454110 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927542751232
   [junit4]   2> 454111 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoute in=9996ms
   [junit4]   2> 454112 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 454112 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 454112 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard3 to Terms{values={core_node10=0, core_node12=0}, version=1}
   [junit4]   2> 454112 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard3
   [junit4]   2> 454113 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 454113 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 454114 INFO  (searcherExecutor-3388-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard2_replica_n5 c:collection1 s:shard2 r:core_node6) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SolrCore [collection1_shard2_replica_n5]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454116 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 454116 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 454116 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40485/solr/collection1_shard3_replica_n9/
   [junit4]   2> 454117 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
   [junit4]   2> 454125 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard3_replica_n9 url=http://127.0.0.1:40485/solr  START replicas=[http://127.0.0.1:40485/solr/collection1_shard3_replica_n11/] nUpdates=100
   [junit4]   2> 454125 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard1 to Terms{values={core_node2=0, core_node4=0}, version=1}
   [junit4]   2> 454125 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard1
   [junit4]   2> 454125 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
   [junit4]   2> 454125 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 454125 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697597927558479872
   [junit4]   2> 454127 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard3_replica_n9 url=http://127.0.0.1:40485/solr  DONE. We have no versions. sync failed.
   [junit4]   2> 454129 INFO  (qtp289385215-5353) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.S.Request [collection1_shard3_replica_n11]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 454129 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 454129 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 454129 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard3/leader after winning as /collections/collection1/leader_elect/shard3/election/73368427751342085-core_node10-n_0000000000
   [junit4]   2> 454130 INFO  (searcherExecutor-3386-thread-1-processing-n:127.0.0.1:40485_solr x:collection1_shard2_replica_n7 c:collection1 s:shard2 r:core_node8) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SolrCore [collection1_shard2_replica_n7]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 454135 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40485/solr/collection1_shard3_replica_n9/ shard3
   [junit4]   2> 454136 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard2 to Terms{values={core_node6=0}, version=0}
   [junit4]   2> 454136 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard2
   [junit4]   2> 454137 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/collection1/terms/shard2 to Terms{values={core_node6=0, core_node8=0}, version=1}
   [junit4]   2> 454137 INFO  (qtp289385215-5309) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/collection1/leaders/shard2
   [junit4]   2> 454141 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 454143 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 454143 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 454143 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40485/solr/collection1_shard2_replica_n5/
   [junit4]   2> 454144 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica_n5 url=http://127.0.0.1:40485/solr  START replicas=[http://127.0.0.1:40485/solr/collection1_shard2_replica_n7/] nUpdates=100
   [junit4]   2> 454146 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica_n5 url=http://127.0.0.1:40485/solr  DONE. We have no versions. sync failed.
   [junit4]   2> 454147 INFO  (qtp289385215-5353) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.S.Request [collection1_shard2_replica_n7]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 454147 INFO  (qtp289385215-5311) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node10&collection.configName=config&newCollection=true&name=collection1_shard3_replica_n9&action=CREATE&numShards=3&collection=collection1&shard=shard3&wt=javabin&version=2&replicaType=NRT} status=0 QTime=245
   [junit4]   2> 454148 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 454148 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 454148 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard2/leader after winning as /collections/collection1/leader_elect/shard2/election/73368427751342085-core_node6-n_0000000000
   [junit4]   2> 454148 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454149 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40485/solr/collection1_shard2_replica_n5/ shard2
   [junit4]   2> 454149 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454149 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454150 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454150 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454151 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 454155 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454155 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454157 INFO  (qtp289385215-5313) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=config&newCollection=true&name=collection1_shard2_replica_n5&action=CREATE&numShards=3&collection=collection1&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=255
   [junit4]   2> 454612 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 454612 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
   [junit4]   2> 454612 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:40485/solr/collection1_shard1_replica_n3/
   [junit4]   2> 454612 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n3 url=http://127.0.0.1:40485/solr  START replicas=[http://127.0.0.1:40485/solr/collection1_shard1_replica_n1/] nUpdates=100
   [junit4]   2> 454612 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n3 url=http://127.0.0.1:40485/solr  DONE. We have no versions. sync failed.
   [junit4]   2> 454613 INFO  (qtp289385215-5353) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.S.Request [collection1_shard1_replica_n1]  webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
   [junit4]   2> 454614 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
   [junit4]   2> 454614 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
   [junit4]   2> 454614 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/73368427751342085-core_node4-n_0000000000
   [junit4]   2> 454616 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:40485/solr/collection1_shard1_replica_n3/ shard1
   [junit4]   2> 454616 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454616 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454618 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 454619 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454619 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 454620 INFO  (qtp289385215-5312) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=config&newCollection=true&name=collection1_shard1_replica_n3&action=CREATE&numShards=3&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=720
   [junit4]   2> 455120 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 455120 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 455123 INFO  (qtp289385215-5352) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node12&collection.configName=config&newCollection=true&name=collection1_shard3_replica_n11&action=CREATE&numShards=3&collection=collection1&shard=shard3&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1219
   [junit4]   2> 455133 INFO  (zkCallback-3366-thread-2) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 455133 INFO  (zkCallback-3366-thread-4) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 455135 INFO  (qtp289385215-5351) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=config&newCollection=true&name=collection1_shard1_replica_n1&action=CREATE&numShards=3&collection=collection1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1234
   [junit4]   2> 543956 WARN  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker-SendThread(127.0.0.1:38793)) [     ] o.a.z.ClientCnxn An exception was thrown while closing send thread for session 0x104a83241d90006.
   [junit4]   2>           => EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90006, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77)
   [junit4]   2> org.apache.zookeeper.ClientCnxn$EndOfStreamException: Unable to read additional data from server sessionid 0x104a83241d90006, likely server has closed socket
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doIO(ClientCnxnSocketNIO.java:77) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350) ~[zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1275) [zookeeper-3.6.2.jar:3.6.2]
   [junit4]   2> 573998 ERROR (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.a.c.OverseerCollectionMessageHandler Error from shard: http://127.0.0.1:40485/solr
   [junit4]   2>           => org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:40485/solr
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:692)
   [junit4]   2> org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:40485/solr
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:692) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:266) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1290) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.handler.component.HttpShardHandlerFactory$1.request(HttpShardHandlerFactory.java:169) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.handler.component.ShardRequestor.call(ShardRequestor.java:130) ~[java/:?]
   [junit4]   2> 	at org.apache.solr.handler.component.ShardRequestor.call(ShardRequestor.java:41) ~[java/:?]
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_281]
   [junit4]   2> 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_281]
   [junit4]   2> 	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_281]
   [junit4]   2> 	at com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:180) ~[metrics-core-4.1.5.jar:4.1.5]
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:218) ~[java/:?]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_281]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_281]
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_281]
   [junit4]   2> Caused by: java.net.SocketTimeoutException: Read timed out
   [junit4]   2> 	at java.net.SocketInputStream.socketRead0(Native Method) ~[?:1.8.0_281]
   [junit4]   2> 	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[?:1.8.0_281]
   [junit4]   2> 	at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[?:1.8.0_281]
   [junit4]   2> 	at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_281]
   [junit4]   2> 	at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125) ~[httpcore-4.4.13.jar:4.4.13]
   [junit4]   2> 	at org.apache.solr.util.stats.InstrumentedHttpRequestExecutor.execute(InstrumentedHttpRequestExecutor.java:120) ~[java/:?]
   [junit4]   2> 	at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56) ~[httpclient-4.5.12.jar:4.5.12]
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:571) ~[java/:?]
   [junit4]   2> 	... 14 more
   [junit4]   2> 633871 ERROR (qtp289385215-5310) [n:127.0.0.1:40485_solr     ] o.a.s.h.RequestHandlerBase org.apache.solr.common.SolrException: create the collection time out:180s
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.sendToOCPQueue(CollectionsHandler.java:394)
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:299)
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:257)
   [junit4]   2> 	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:216)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:836)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:800)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:545)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:427)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:357)
   [junit4]   2> 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)
   [junit4]   2> 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1612)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1582)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
   [junit4]   2> 	at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:766)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
   [junit4]   2> 	at org.eclipse.jetty.server.Server.handle(Server.java:516)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
   [junit4]   2> 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
   [junit4]   2> 	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 633871 INFO  (qtp289385215-5310) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=config&maxShardsPerNode=6&name=collection1&nrtReplicas=2&action=CREATE&numShards=3&perReplicaState=true&wt=javabin&version=2} status=500 QTime=180003
   [junit4]   2> 633871 ERROR (qtp289385215-5310) [n:127.0.0.1:40485_solr     ] o.a.s.s.HttpSolrCall org.apache.solr.common.SolrException: create the collection time out:180s
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.sendToOCPQueue(CollectionsHandler.java:394)
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.invokeAction(CollectionsHandler.java:299)
   [junit4]   2> 	at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:257)
   [junit4]   2> 	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:216)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:836)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:800)
   [junit4]   2> 	at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:545)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:427)
   [junit4]   2> 	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:357)
   [junit4]   2> 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
   [junit4]   2> 	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)
   [junit4]   2> 	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1612)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1434)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
   [junit4]   2> 	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
   [junit4]   2> 	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1582)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1349)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
   [junit4]   2> 	at org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:766)
   [junit4]   2> 	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
   [junit4]   2> 	at org.eclipse.jetty.server.Server.handle(Server.java:516)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:556)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
   [junit4]   2> 	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
   [junit4]   2> 	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
   [junit4]   2> 	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
   [junit4]   2> 	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
   [junit4]   2> 	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 633900 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1492942849
   [junit4]   2> 633900 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:40485_solr
   [junit4]   2> 633901 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.c.ZkController Publish this node as DOWN...
   [junit4]   2> 633901 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.c.ZkController Publish node=127.0.0.1:40485_solr as DOWN
   [junit4]   2> 633910 INFO  (coreCloseExecutor-3423-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard3_replica_n9]  CLOSING SolrCore org.apache.solr.core.SolrCore@24cfc925
   [junit4]   2> 633910 INFO  (coreCloseExecutor-3423-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard3.replica_n9 tag=SolrCore@24cfc925
   [junit4]   2> 633910 INFO  (coreCloseExecutor-3423-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard3.leader tag=SolrCore@24cfc925
   [junit4]   2> 633911 INFO  (coreCloseExecutor-3423-thread-1) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633919 INFO  (coreCloseExecutor-3423-thread-2) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard1_replica_n3]  CLOSING SolrCore org.apache.solr.core.SolrCore@549c34cf
   [junit4]   2> 633919 INFO  (coreCloseExecutor-3423-thread-2) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard1.replica_n3 tag=SolrCore@549c34cf
   [junit4]   2> 633919 INFO  (coreCloseExecutor-3423-thread-2) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard1.leader tag=SolrCore@549c34cf
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-3) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard1_replica_n1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3fd78f3e
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-3) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard1.replica_n1 tag=SolrCore@3fd78f3e
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-3) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard1.leader tag=SolrCore@3fd78f3e
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-2) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-4) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard3_replica_n11]  CLOSING SolrCore org.apache.solr.core.SolrCore@57b80c11
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-4) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard3.replica_n11 tag=SolrCore@57b80c11
   [junit4]   2> 633920 INFO  (coreCloseExecutor-3423-thread-4) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard3.leader tag=SolrCore@57b80c11
   [junit4]   2> 633921 INFO  (coreCloseExecutor-3423-thread-3) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633921 INFO  (coreCloseExecutor-3423-thread-5) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard2_replica_n5]  CLOSING SolrCore org.apache.solr.core.SolrCore@186c765e
   [junit4]   2> 633921 INFO  (coreCloseExecutor-3423-thread-4) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633921 INFO  (coreCloseExecutor-3423-thread-5) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard2.replica_n5 tag=SolrCore@186c765e
   [junit4]   2> 633921 INFO  (coreCloseExecutor-3423-thread-5) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard2.leader tag=SolrCore@186c765e
   [junit4]   2> 633923 INFO  (coreCloseExecutor-3423-thread-6) [n:127.0.0.1:40485_solr     ] o.a.s.c.SolrCore [collection1_shard2_replica_n7]  CLOSING SolrCore org.apache.solr.core.SolrCore@1739c1d6
   [junit4]   2> 633923 INFO  (coreCloseExecutor-3423-thread-6) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard2.replica_n7 tag=SolrCore@1739c1d6
   [junit4]   2> 633923 INFO  (coreCloseExecutor-3423-thread-6) [n:127.0.0.1:40485_solr     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard2.leader tag=SolrCore@1739c1d6
   [junit4]   2> 633924 INFO  (coreCloseExecutor-3423-thread-5) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633924 INFO  (zkCallback-3366-thread-5) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 633925 INFO  (coreCloseExecutor-3423-thread-6) [n:127.0.0.1:40485_solr     ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close()  ... SKIPPED (unnecessary).
   [junit4]   2> 633924 INFO  (zkCallback-3366-thread-6) [     ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [1])
   [junit4]   2> 633936 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node tag=null
   [junit4]   2> 633936 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
   [junit4]   2> 633936 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.m.SolrMetricManager Closing met

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

ommon.cloud.SolrZkClient.setData(SolrZkClient.java:363)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:583)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskQueue.remove(OverseerTaskQueue.java:118)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.markTaskComplete(OverseerTaskProcessor.java:601)
   [junit4]   2> 	at org.apache.solr.cloud.OverseerTaskProcessor$Runner.run(OverseerTaskProcessor.java:550)
   [junit4]   2> 	at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:218)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> 
   [junit4]   2> 634042 WARN  (OverseerThreadFactory-3374-thread-1-processing-n:127.0.0.1:40485_solr) [n:127.0.0.1:40485_solr     ] o.a.s.c.OverseerTaskProcessor Resetting task: /overseer/collection-queue-work/qn-0000000000, requestid: null, taskKey: collection1
   [junit4]   2> 634042 INFO  (OverseerAutoScalingTriggerThread-73368427751342085-127.0.0.1:40485_solr-n_0000000000) [     ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
   [junit4]   2> 634043 INFO  (jetty-closer-3419-thread-1) [     ] o.a.s.c.Overseer Overseer (id=73368427751342085-127.0.0.1:40485_solr-n_0000000000) closing
   [junit4]   2> 634043 INFO  (closeThreadPool-3425-thread-1) [     ] o.a.s.c.Overseer Overseer (id=73368427751342085-127.0.0.1:40485_solr-n_0000000000) closing
   [junit4]   2> 634045 INFO  (jetty-closer-3419-thread-1) [     ] o.e.j.s.AbstractConnector Stopped ServerConnector@1ff846a8{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
   [junit4]   2> 634045 INFO  (jetty-closer-3419-thread-1) [     ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6d1c63c9{/solr,null,STOPPED}
   [junit4]   2> 634045 INFO  (jetty-closer-3419-thread-1) [     ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 634046 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
   [junit4]   2> 634249 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> 	3	/solr/collections/collection1/terms/shard3
   [junit4]   2> 	3	/solr/collections/collection1/terms/shard1
   [junit4]   2> 	2	/solr/collections/collection1/terms/shard2
   [junit4]   2> 	2	/solr/aliases.json
   [junit4]   2> 	2	/solr/clusterprops.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	7	/solr/collections/collection1/state.json
   [junit4]   2> 	2	/solr/clusterstate.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	24	/solr/collections/collection1/state.json
   [junit4]   2> 	11	/solr/overseer/queue
   [junit4]   2> 	4	/solr/collections
   [junit4]   2> 	4	/solr/overseer/collection-queue-work
   [junit4]   2> 	3	/solr/live_nodes
   [junit4]   2> 
   [junit4]   2> 634251 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:38793
   [junit4]   2> 634251 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38793
   [junit4]   2> 634251 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38793
   [junit4]   2> 634252 INFO  (SUITE-HttpSolrCallGetCoreTest-seed#[EA919446BA2ED35B]-worker) [     ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
   [junit4]   2> Apr 20, 2021 9:55:23 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene87): {}, docValues:{}, maxPointsInLeafNode=1018, maxMBSortInHeap=7.844770814630981, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=sr-RS, timezone=America/St_Thomas
   [junit4]   2> NOTE: Linux 5.4.0-45-generic amd64/Oracle Corporation 1.8.0_281 (64-bit)/cpus=4,threads=1,free=305999952,total=497025024
   [junit4]   2> NOTE: All tests run in this JVM: [TestMultiWordSynonyms, TestManagedSchema, TestHttpServletCarrier, TestDynamicFieldNamesIndexCorrectly, FieldMutatingUpdateProcessorTest, TestNRTOpen, IndexSchemaRuntimeFieldTest, TokenizerChainTest, HDFSCollectionsAPITest, TestCollectionAPIs, TestTlogReplica, TestNumericRangeQuery64, DateMathParserTest, MissingSegmentRecoveryTest, SharedFSAutoReplicaFailoverTest, ConnectionManagerTest, DistributedDebugComponentTest, TestSolrDeletionPolicy2, TestScoreJoinQPNoScore, TestSchemaSimilarityResource, TestRandomFaceting, CursorMarkTest, TestCaffeineCache, TestNamedUpdateProcessors, TestManagedStopFilterFactory, BadIndexSchemaTest, MultiSolrCloudTestCaseTest, TestSimScenario, RollingRestartTest, AddSchemaFieldsUpdateProcessorFactoryTest, ForceLeaderWithTlogReplicasTest, SmileWriterTest, TestFieldTypeCollectionResource, IndexSizeTriggerSizeEstimationTest, TestShardHandlerFactory, TriLevelCompositeIdRoutingTest, ExitableDirectoryReaderTest, TestHdfsBackupRestoreCore, TestEmbeddedSolrServerSchemaAPI, HighlighterWithoutStoredIdTest, DistributedQueueTest, TestRTGBase, HttpSolrCallGetCoreTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HttpSolrCallGetCoreTest -Dtests.seed=EA919446BA2ED35B -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=sr-RS -Dtests.timezone=America/St_Thomas -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J3 | HttpSolrCallGetCoreTest (suite) <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:40485/solr
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([EA919446BA2ED35B]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:692)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:266)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:369)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:297)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1171)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:934)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:866)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:214)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:231)
   [junit4]    > 	at org.apache.solr.servlet.HttpSolrCallGetCoreTest.setupCluster(HttpSolrCallGetCoreTest.java:53)
   [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:280)
   [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:157)
   [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:186)
   [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:571)
   [junit4]    > 	... 36 more
   [junit4] Completed [206/936 (1!)] on J3 in 182.09s, 0 tests, 1 error <<< FAILURES!

[...truncated 53320 lines...]

[JENKINS] Lucene » Lucene-Solr-Tests-8.x - Build # 2158 - Still Unstable!

Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://ci-builds.apache.org/job/Lucene/job/Lucene-Solr-Tests-8.x/2158/

1 tests failed.
FAILED:  org.apache.solr.handler.component.DistributedSpellCheckComponentTest.test

Error Message:
Error from server at https://127.0.0.1:46133/twwr/m/collection1: org.apache.solr.client.solrj.SolrServerException: java.lang.ArithmeticException: / by zero

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:46133/twwr/m/collection1: org.apache.solr.client.solrj.SolrServerException: java.lang.ArithmeticException: / by zero
	at __randomizedtesting.SeedInfo.seed([8296CFFA0741DD8C:AC2F020A9BDB074]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:681)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:266)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:214)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1003)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1018)
	at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:625)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:677)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:655)
	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:634)
	at org.apache.solr.handler.component.DistributedSpellCheckComponentTest.test(DistributedSpellCheckComponentTest.java:149)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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 org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1117)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1061)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	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 org.junit.rules.RunRules.evaluate(RunRules.java:20)
	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.junit.rules.RunRules.evaluate(RunRules.java:20)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
	at org.junit.rules.RunRules.evaluate(RunRules.java:20)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
	at java.lang.Thread.run(Thread.java:748)




Build Log:
[...truncated 15500 lines...]
   [junit4] Suite: org.apache.solr.handler.component.DistributedSpellCheckComponentTest
   [junit4]   2> 2047708 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/server/solr/configsets/_default/conf'
   [junit4]   2> 2047708 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> 2047709 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/data-dir-153-001
   [junit4]   2> 2047709 WARN  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=13 numCloses=13
   [junit4]   2> 2047709 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
   [junit4]   2> 2047710 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
   [junit4]   2> 2047711 INFO  (SUITE-DistributedSpellCheckComponentTest-seed#[8296CFFA0741DD8C]-worker) [     ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /twwr/m
   [junit4]   2> 2047814 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/cores/collection1
   [junit4]   2> 2047816 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 2047816 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
   [junit4]   2> 2047816 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.Server jetty-9.4.34.v20201102; built: 2020-11-02T14:15:39.302Z; git: e46af88704a893fc12cb0e3bf46e2c7b48a009e7; jvm 1.8.0_281-b09
   [junit4]   2> 2047817 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2047817 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2047817 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 2047819 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@71dc8367{/twwr/m,null,AVAILABLE}
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.AbstractConnector Started ServerConnector@31a8c20a{SSL, (ssl, http/1.1)}{127.0.0.1:35659}
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.Server Started @2047851ms
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/twwr/m, hostPort=35659, coreRootDirectory=/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/cores}
   [junit4]   2> 2047820 ERROR (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.9.0
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2021-04-21T00:49:43.195Z
   [junit4]   2> 2047820 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/solr.xml
   [junit4]   2> 2047822 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 2047822 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 2047824 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 2048654 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
   [junit4]   2> 2048654 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 2048657 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@108d09b4[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2048657 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@108d09b4[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2048661 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 2048662 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@233c48e9[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2048662 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@233c48e9[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2048663 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CoreContainer Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info
   [junit4]   2> 2048689 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
   [junit4]   2> 2048689 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 2048711 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2048720 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2048720 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2048722 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/cores
   [junit4]   2> 2048722 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2048737 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.c.SolrResourceLoader Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 2048756 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 2048779 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.s.IndexSchema Schema name=test
   [junit4]   2> 2048786 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2048793 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 2048793 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2048793 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/cores/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/control/cores/collection1/data/]
   [junit4]   2> 2048795 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 2048873 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 2048873 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2048874 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2048874 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2048875 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=11.4248046875, floorSegmentMB=1.6240234375, forceMergeDeletesPctAllowed=2.94672174350445, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5166313098441065, deletesPctAllowed=37.365316088758604
   [junit4]   2> 2048877 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 2048891 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2048954 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 2048954 INFO  (coreLoadExecutor-21075-thread-1) [    x:collection1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697609085698965504
   [junit4]   2> 2048955 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 2048956 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 2048956 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 2048956 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 2048957 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 2048957 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 2048957 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 2048961 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 2048961 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 2048963 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.c.SolrCore [collection1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 2049276 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/cores/collection1
   [junit4]   2> 2049278 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
   [junit4]   2> 2049278 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
   [junit4]   2> 2049278 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.Server jetty-9.4.34.v20201102; built: 2020-11-02T14:15:39.302Z; git: e46af88704a893fc12cb0e3bf46e2c7b48a009e7; jvm 1.8.0_281-b09
   [junit4]   2> 2049281 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 2049281 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 2049281 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.session node0 Scavenging every 660000ms
   [junit4]   2> 2049282 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@54f5cd9{/twwr/m,null,AVAILABLE}
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.AbstractConnector Started ServerConnector@3b3f1846{SSL, (ssl, http/1.1)}{127.0.0.1:35913}
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.s.Server Started @2049314ms
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/twwr/m, hostPort=35913, coreRootDirectory=/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/cores}
   [junit4]   2> 2049283 ERROR (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 8.9.0
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on port null
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 2021-04-21T00:49:44.658Z
   [junit4]   2> 2049283 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/solr.xml
   [junit4]   2> 2049285 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored
   [junit4]   2> 2049285 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored
   [junit4]   2> 2049287 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1, but no JMX reporters were configured - adding default JMX reporter.
   [junit4]   2> 2050005 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
   [junit4]   2> 2050005 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 2050006 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@13d9e00e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2050006 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@13d9e00e[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2050008 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
   [junit4]   2> 2050009 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config Trusting all certificates configured for Client@e959df5[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2050009 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@e959df5[provider=null,keyStore=null,trustStore=null]
   [junit4]   2> 2050010 WARN  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CoreContainer Not all security plugins configured!  authentication=disabled authorization=disabled.  Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external.  See https://s.apache.org/solrsecurity for more info
   [junit4]   2> 2050025 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
   [junit4]   2> 2050025 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
   [junit4]   2> 2050053 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2050068 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2050068 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2050070 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/cores
   [junit4]   2> 2050070 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 2050079 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.c.SolrResourceLoader Added 2 libs to classloader, from paths: [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1/lib, /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 2050098 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.0
   [junit4]   2> 2050127 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.s.IndexSchema Schema name=test
   [junit4]   2> 2050138 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 2050147 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from configset /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/core/src/test-files/solr/collection1, trusted=true
   [junit4]   2> 2050147 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@742171a1
   [junit4]   2> 2050147 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/cores/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001/tempDir-001/shard0/cores/collection1/data/]
   [junit4]   2> 2050150 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=45, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 2050221 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 2050221 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2050223 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2050223 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2050224 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=14, maxMergedSegmentMB=11.4248046875, floorSegmentMB=1.6240234375, forceMergeDeletesPctAllowed=2.94672174350445, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5166313098441065, deletesPctAllowed=37.365316088758604
   [junit4]   2> 2050225 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 2050238 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 2050321 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
   [junit4]   2> 2050321 INFO  (coreLoadExecutor-21094-thread-1) [    x:collection1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1697609087132368896
   [junit4]   2> 2050322 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 2050324 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 2050324 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 2050325 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 2050327 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.c.SolrCore [collection1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 2050358 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1697609087168020480)} 0 2
   [junit4]   2> 2050401 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1697609087214157824)} 0 2
   [junit4]   2> 2050404 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[1 (1697609087218352128)]} 0 1
   [junit4]   2> 2050406 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[1 (1697609087220449280)]} 0 1
   [junit4]   2> 2050407 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[2 (1697609087222546432)]} 0 0
   [junit4]   2> 2050408 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[2 (1697609087223595008)]} 0 0
   [junit4]   2> 2050409 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[3 (1697609087224643584)]} 0 0
   [junit4]   2> 2050410 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[3 (1697609087225692160)]} 0 0
   [junit4]   2> 2050411 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[4 (1697609087225692160)]} 0 0
   [junit4]   2> 2050411 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[4 (1697609087226740736)]} 0 0
   [junit4]   2> 2050412 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[5 (1697609087227789312)]} 0 0
   [junit4]   2> 2050413 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[5 (1697609087227789312)]} 0 0
   [junit4]   2> 2050413 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[6 (1697609087228837888)]} 0 0
   [junit4]   2> 2050414 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[6 (1697609087229886464)]} 0 0
   [junit4]   2> 2050414 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[7 (1697609087229886464)]} 0 0
   [junit4]   2> 2050415 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[7 (1697609087230935040)]} 0 0
   [junit4]   2> 2050415 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[8 (1697609087230935040)]} 0 0
   [junit4]   2> 2050416 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[8 (1697609087231983616)]} 0 0
   [junit4]   2> 2050416 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[9 (1697609087231983616)]} 0 0
   [junit4]   2> 2050417 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[9 (1697609087233032192)]} 0 0
   [junit4]   2> 2050417 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[10 (1697609087233032192)]} 0 0
   [junit4]   2> 2050418 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[10 (1697609087234080768)]} 0 0
   [junit4]   2> 2050418 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[12 (1697609087234080768)]} 0 0
   [junit4]   2> 2050419 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[12 (1697609087235129344)]} 0 0
   [junit4]   2> 2050420 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[13 (1697609087235129344)]} 0 0
   [junit4]   2> 2050420 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[13 (1697609087236177920)]} 0 0
   [junit4]   2> 2050421 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[14 (1697609087237226496)]} 0 0
   [junit4]   2> 2050421 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[14 (1697609087237226496)]} 0 0
   [junit4]   2> 2050422 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[15 (1697609087238275072)]} 0 0
   [junit4]   2> 2050423 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[15 (1697609087239323648)]} 0 0
   [junit4]   2> 2050424 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[16 (1697609087239323648)]} 0 0
   [junit4]   2> 2050424 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[16 (1697609087240372224)]} 0 0
   [junit4]   2> 2050425 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[17 (1697609087241420800)]} 0 0
   [junit4]   2> 2050425 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[17 (1697609087241420800)]} 0 0
   [junit4]   2> 2050426 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[18 (1697609087242469376)]} 0 0
   [junit4]   2> 2050426 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[18 (1697609087242469376)]} 0 0
   [junit4]   2> 2050427 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[19 (1697609087243517952)]} 0 0
   [junit4]   2> 2050427 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[19 (1697609087243517952)]} 0 0
   [junit4]   2> 2050428 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[20 (1697609087244566528)]} 0 0
   [junit4]   2> 2050428 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[20 (1697609087244566528)]} 0 0
   [junit4]   2> 2050429 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[21 (1697609087245615104)]} 0 0
   [junit4]   2> 2050430 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[21 (1697609087245615104)]} 0 0
   [junit4]   2> 2050430 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[22 (1697609087246663680)]} 0 0
   [junit4]   2> 2050431 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[22 (1697609087246663680)]} 0 0
   [junit4]   2> 2050432 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[23 (1697609087247712256)]} 0 0
   [junit4]   2> 2050433 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[23 (1697609087249809408)]} 0 0
   [junit4]   2> 2050434 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[24 (1697609087250857984)]} 0 0
   [junit4]   2> 2050435 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[24 (1697609087251906560)]} 0 0
   [junit4]   2> 2050436 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[25 (1697609087252955136)]} 0 0
   [junit4]   2> 2050436 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[25 (1697609087252955136)]} 0 0
   [junit4]   2> 2050437 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[26 (1697609087254003712)]} 0 0
   [junit4]   2> 2050438 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={wt=javabin&version=2}{add=[26 (1697609087254003712)]} 0 0
   [junit4]   2> 2050742 INFO  (searcherExecutor-21077-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.c.SolrCore [collection1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 2050742 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 304
   [junit4]   2> 2051024 INFO  (searcherExecutor-21096-thread-1-processing-x:collection1) [    x:collection1 ] o.a.s.c.SolrCore [collection1]  Registered new searcher autowarm time: 0 ms
   [junit4]   2> 2051024 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/twwr/m path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 281
   [junit4]   2> 2051088 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&spellcheck.build=true&shards.qt=/spellCheckCompRH} hits=25 status=0 QTime=61
   [junit4]   2> 2051243 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70055&rows=10&version=2&spellcheck.build=true&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=false&q=*:*&spellcheck=true&omitHeader=false&NOW=1618966186464&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=5&wt=javabin} hits=25 status=0 QTime=60
   [junit4]   2> 2051245 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&shards.purpose=64&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70055&version=2&spellcheck.build=true&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=false&q=*:*&spellcheck=false&omitHeader=false&NOW=1618966186464&spellcheck.onlyMorePopular=false&ids=1,2,3,4,5,6,7,8,9,10&isShard=true&spellcheck.count=1&wt=javabin} status=0 QTime=0
   [junit4]   2> 2051250 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051250 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051251 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&shards=https://127.0.0.1:35913/twwr/m/collection1&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&spellcheck.build=true&shards.qt=/spellCheckCompRH} rid=127.0.0.1-70055 hits=25 status=0 QTime=161
   [junit4]   2> 2051288 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&spellcheck.q=toyata&distrib=false&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&group.field=id&shards.qt=/spellCheckCompRH&group=true} hits=25 status=0 QTime=26
   [junit4]   2> 2051300 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&group.distributed.first=true&distrib=false&qt=/spellCheckCompRH&fl=id,score&shards.purpose=2048&start=0&shard.url=[::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70057&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=false&q=*:*&spellcheck.q=toyata&spellcheck=true&omitHeader=false&NOW=1618966186671&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=5&wt=javabin&group.field=id&group=true} status=0 QTime=1
   [junit4]   2> 2051302 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&fl=id,score&shards.purpose=4&shard.url=[::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70057&spellcheck.q=toyata&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&group.topgroups.id=1&group.topgroups.id=2&group.topgroups.id=3&group.topgroups.id=4&group.topgroups.id=5&group.topgroups.id=6&group.topgroups.id=7&group.topgroups.id=8&group.topgroups.id=9&group.topgroups.id=10&version=2&group.distributed.second=true&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=false&q=*:*&spellcheck=false&omitHeader=false&NOW=1618966186671&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=1} status=0 QTime=0
   [junit4]   2> 2051304 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&shards.purpose=64&shard.url=[::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70057&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=false&q=*:*&spellcheck.q=toyata&spellcheck=false&omitHeader=false&NOW=1618966186671&spellcheck.onlyMorePopular=false&ids=1,2,3,4,5,6,7,8,9,10&isShard=true&spellcheck.count=1&wt=javabin&group.field=id} status=0 QTime=0
   [junit4]   2> 2051305 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 {suggestions={toyata={numFound=2,startOffset=0,endOffset=6,suggestion=[toyota, sonata]}},originalTerms=[toyata]}
   [junit4]   2> 2051305 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051305 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051305 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&shards=[::1]:8/twwr/m|[::1]:4/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&spellcheck.q=toyata&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&group.field=id&shards.qt=/spellCheckCompRH&group=true} rid=127.0.0.1-70057 status=0 QTime=9
   [junit4]   2> 2051307 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&spellcheck.q=toyata&distrib=false&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true} hits=25 status=0 QTime=0
   [junit4]   2> 2051309 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70059&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=*:*&spellcheck.q=toyata&spellcheck=true&omitHeader=false&NOW=1618966186683&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=5&wt=javabin} hits=25 status=0 QTime=0
   [junit4]   2> 2051310 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&shards.purpose=64&shard.url=[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70059&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=*:*&spellcheck.q=toyata&spellcheck=false&omitHeader=false&NOW=1618966186683&spellcheck.onlyMorePopular=false&ids=1,2,3,4,5,6,7,8,9,10&isShard=true&spellcheck.count=1&wt=javabin} status=0 QTime=0
   [junit4]   2> 2051313 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 {suggestions={toyata={numFound=2,startOffset=0,endOffset=6,origFreq=0,suggestion=[{word=toyota,freq=1}, {word=sonata,freq=1}]}},correctlySpelled=true,originalTerms=[toyata]}
   [junit4]   2> 2051313 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051313 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&shards=[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&spellcheck.q=toyata&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&wt=javabin&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true} rid=127.0.0.1-70059 hits=25 status=0 QTime=5
   [junit4]   2> 2051315 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&spellcheck.q=bluo&distrib=false&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&spellcheck.count=4&wt=javabin&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true} hits=25 status=0 QTime=0
   [junit4]   2> 2051326 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=[::1]:4/twwr/m|[::1]:8/twwr/m|[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70061&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=*:*&spellcheck.q=bluo&spellcheck=true&omitHeader=false&NOW=1618966186691&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=5&wt=javabin} hits=25 status=0 QTime=1
   [junit4]   2> 2051330 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&shards.purpose=64&shard.url=[::1]:4/twwr/m|[::1]:8/twwr/m|[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70061&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=*:*&spellcheck.q=bluo&spellcheck=false&omitHeader=false&NOW=1618966186691&spellcheck.onlyMorePopular=false&ids=1,2,3,4,5,6,7,8,9,10&isShard=true&spellcheck.count=4&wt=javabin} status=0 QTime=0
   [junit4]   2> 2051331 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:4/twwr/m|[::1]:8/twwr/m|[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 {suggestions={bluo={numFound=2,startOffset=0,endOffset=4,origFreq=0,suggestion=[{word=blue,freq=1}, {word=glue,freq=1}]}},correctlySpelled=true,originalTerms=[bluo]}
   [junit4]   2> 2051331 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:4/twwr/m|[::1]:8/twwr/m|[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051331 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={q=*:*&shards=[::1]:4/twwr/m|[::1]:8/twwr/m|[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&spellcheck.q=bluo&qt=/spellCheckCompRH&spellcheck=true&fl=id,lowerfilt&spellcheck.count=4&wt=javabin&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true} rid=127.0.0.1-70061 hits=25 status=0 QTime=15
   [junit4]   2> 2051348 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=The+quick+reb+fox+jumped+over+the+lazy+brown+dogs&spellcheck=true&spellcheck.count=4&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=15
   [junit4]   2> 2051352 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={df=text&group.distributed.first=true&distrib=false&qt=/spellCheckCompRH&fl=id,score&shards.purpose=2048&start=0&shard.url=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70063&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=The+quick+reb+fox+jumped+over+the+lazy+brown+dogs&spellcheck=true&omitHeader=false&NOW=1618966186725&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=5&wt=javabin&group.field=id&group=true&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051355 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 {suggestions={reb={numFound=1,startOffset=10,endOffset=13,origFreq=0,suggestion=[{word=red,freq=14}]},dogs={numFound=1,startOffset=45,endOffset=49,origFreq=0,suggestion=[{word=dogs.,freq=14}]}},correctlySpelled=false,collations={collation=The quick red fox jumped over the lazy brown dogs.},originalTerms=[the, quick, reb, fox, jumped, over, the, lazy, brown, dogs]}
   [junit4]   2> 2051355 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={qt=/spellCheckCompRH&fl=id,lowerfilt&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=The+quick+reb+fox+jumped+over+the+lazy+brown+dogs&shards=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&spellcheck=true&spellcheck.count=4&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70063 status=0 QTime=5
   [junit4]   2> 2051358 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=true&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&spellcheck.count=10&wt=javabin&spellcheck.collate=true} hits=0 status=0 QTime=2
   [junit4]   2> 2051363 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=true&df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&spellcheck.maxCollations=10&fsv=true&spellcheck.maxCollationTries=10&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70065&wt=javabin&qt=/spellCheckCompRH&start=0&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&omitHeader=false&NOW=1618966186736&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051369 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 {suggestions={quock={numFound=2,startOffset=12,endOffset=17,origFreq=0,suggestion=[{word=quick,freq=1}, {word=quote,freq=12}]},reb={numFound=1,startOffset=19,endOffset=22,origFreq=0,suggestion=[{word=red,freq=14}]}},correctlySpelled=false,collations={collation={collationQuery=lowerfilt:(+quick +red),hits=1,misspellingsAndCorrections={quock=quick,reb=red},collationInternalRank=0},collation={collationQuery=lowerfilt:(+quote +red),hits=12,misspellingsAndCorrections={quock=quote,reb=red},collationInternalRank=1}},originalTerms=[quock, reb]}
   [junit4]   2> 2051369 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=true&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&shards=https://127.0.0.1:35913/twwr/m/collection1&spellcheck=true&spellcheck.count=10&wt=javabin&spellcheck.collate=true} rid=127.0.0.1-70065 hits=0 status=0 QTime=8
   [junit4]   2> 2051372 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051375 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&group.distributed.first=true&distrib=false&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&shard.url=https://127.0.0.1:35913/twwr/m/collection1|[::1]:8/twwr/m&rid=127.0.0.1-70067&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&omitHeader=false&NOW=1618966186748&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051375 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1|[::1]:8/twwr/m {suggestions={quock={numFound=2,startOffset=12,endOffset=17,origFreq=0,suggestion=[{word=quick,freq=1}, {word=quote,freq=12}]},reb={numFound=1,startOffset=19,endOffset=22,origFreq=0,suggestion=[{word=red,freq=14}]}},correctlySpelled=false,collations={collation=lowerfilt:(+quick +red),collationInternalRank=0,collation=lowerfilt:(+quote +red),collationInternalRank=1},originalTerms=[quock, reb]}
   [junit4]   2> 2051376 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=10&spellcheck.maxCollationTries=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&shards=https://127.0.0.1:35913/twwr/m/collection1|[::1]:8/twwr/m&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70067 status=0 QTime=2
   [junit4]   2> 2051377 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051380 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&group.distributed.first=true&distrib=false&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&shard.url=https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m|[::1]:8/twwr/m|[::1]:4/twwr/m&rid=127.0.0.1-70069&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&spellcheck=true&omitHeader=false&NOW=1618966186753&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051381 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m|[::1]:8/twwr/m|[::1]:4/twwr/m {suggestions={quock={numFound=2,startOffset=12,endOffset=17,origFreq=0,suggestion=[{word=quick,freq=1}, {word=quote,freq=12}]},reb={numFound=1,startOffset=19,endOffset=22,origFreq=0,suggestion=[{word=red,freq=14}]}},correctlySpelled=false,collations={collation=lowerfilt:(+quick +red)},originalTerms=[quock, reb]}
   [junit4]   2> 2051381 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Breb)&shards=https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m|[::1]:8/twwr/m|[::1]:4/twwr/m&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70069 status=0 QTime=2
   [junit4]   2> 2051387 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("quick+red+fox")&spellcheck.maxResultsForSuggest=10&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=1 status=0 QTime=5
   [junit4]   2> 2051390 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&group.distributed.first=true&distrib=false&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70071&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("quick+red+fox")&spellcheck=true&omitHeader=false&NOW=1618966186763&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051396 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&distrib=false&fl=id,score&shards.purpose=4&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70071&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&group.topgroups.id=9&spellcheck.alternativeTermCount=5&version=2&group.distributed.second=true&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("quick+red+fox")&spellcheck=false&omitHeader=false&NOW=1618966186763&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051398 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&distrib=false&fl=id,lowerfilt&shards.purpose=64&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70071&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&qt=/spellCheckCompRH&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("quick+red+fox")&spellcheck=false&omitHeader=false&NOW=1618966186763&spellcheck.onlyMorePopular=false&ids=9&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051399 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 {suggestions={quick={numFound=1,startOffset=12,endOffset=17,origFreq=1,suggestion=[{word=quicker,freq=1}]},red={numFound=1,startOffset=18,endOffset=21,origFreq=14,suggestion=[{word=rod,freq=1}]},fox={numFound=2,startOffset=22,endOffset=25,origFreq=14,suggestion=[{word=fix,freq=1}, {word=ford,freq=1}]}},correctlySpelled=false,collations={collation=lowerfilt:("quicker red fox"),collationInternalRank=1},originalTerms=[quick, red, fox]}
   [junit4]   2> 2051399 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051399 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051399 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("quick+red+fox")&shards=[::1]:6/twwr/m|[::1]:8/twwr/m|https://127.0.0.1:35913/twwr/m/collection1&spellcheck.maxResultsForSuggest=10&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70071 status=0 QTime=11
   [junit4]   2> 2051402 INFO  (qtp1029892502-33704) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck.maxResultsForSuggest=10&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=1 status=0 QTime=1
   [junit4]   2> 2051405 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&group.distributed.first=true&distrib=false&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70073&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck=true&omitHeader=false&NOW=1618966186778&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051408 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&distrib=false&fl=id,score&shards.purpose=4&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70073&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&group=true&qt=/spellCheckCompRH&start=0&rows=10&group.topgroups.id=26&spellcheck.alternativeTermCount=5&version=2&group.distributed.second=true&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck=false&omitHeader=false&NOW=1618966186778&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051410 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&distrib=false&fl=id,lowerfilt&shards.purpose=64&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70073&spellcheck.maxResultsForSuggest=10&wt=javabin&group.field=id&qt=/spellCheckCompRH&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck=false&omitHeader=false&NOW=1618966186778&spellcheck.onlyMorePopular=false&ids=26&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051410 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 {suggestions={rod={numFound=2,startOffset=12,endOffset=15,origFreq=1,suggestion=[{word=red,freq=14}, {word=ford,freq=1}]},fix={numFound=1,startOffset=16,endOffset=19,origFreq=1,suggestion=[{word=fox,freq=14}]}},correctlySpelled=false,collations={collation=lowerfilt:("red fox"),collationInternalRank=2},originalTerms=[rod, fix]}
   [junit4]   2> 2051410 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051410 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 null
   [junit4]   2> 2051410 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&shards=https://127.0.0.1:35913/twwr/m/collection1&spellcheck.maxResultsForSuggest=10&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70073 status=0 QTime=7
   [junit4]   2> 2051413 INFO  (qtp1029892502-33698) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&distrib=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&fq=id:[13+TO+22]&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck.maxResultsForSuggest=.10&spellcheck=true&spellcheck.count=10&wt=javabin&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051417 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&spellcheck.maxCollations=1&fsv=true&spellcheck.maxCollationTries=10&fq=id:[13+TO+22]&shard.url=https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m&rid=127.0.0.1-70075&spellcheck.maxResultsForSuggest=.10&wt=javabin&qt=/spellCheckCompRH&start=0&rows=10&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&spellcheck=true&omitHeader=false&NOW=1618966186789&spellcheck.onlyMorePopular=false&isShard=true&spellcheck.count=10&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051417 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m {suggestions={rod={numFound=2,startOffset=12,endOffset=15,origFreq=1,suggestion=[{word=red,freq=14}, {word=ford,freq=1}]},fix={numFound=1,startOffset=16,endOffset=19,origFreq=1,suggestion=[{word=fox,freq=14}]}},correctlySpelled=false,collations={collation=lowerfilt:("red fox"),collationInternalRank=2},originalTerms=[rod, fix]}
   [junit4]   2> 2051417 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckCompRH params={spellcheck.collateExtendedResults=false&qt=/spellCheckCompRH&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=10&fq=id:[13+TO+22]&spellcheck.alternativeTermCount=5&version=2&shards.qt=/spellCheckCompRH&spellcheck.extendedResults=true&q=lowerfilt:("rod+fix")&shards=https://127.0.0.1:35913/twwr/m/collection1|[::1]:6/twwr/m&spellcheck.maxResultsForSuggest=.10&spellcheck=true&spellcheck.count=10&wt=javabin&spellcheck.collate=true} rid=127.0.0.1-70075 hits=0 status=0 QTime=3
   [junit4]   2> 2051428 INFO  (qtp1029892502-33701) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&distrib=false&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Bredfox+%2Bjum+%2Bped)&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=9
   [junit4]   2> 2051432 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&df=text&group.distributed.first=true&distrib=false&spellcheck.dictionary=default&spellcheck.dictionary=wordbreak&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&shard.url=[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1|[::1]:4/twwr/m|[::1]:8/twwr/m&rid=127.0.0.1-70077&wt=javabin&group.field=id&group=true&qt=/spellCheckWithWordbreak&start=0&rows=10&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Bredfox+%2Bjum+%2Bped)&spellcheck=true&omitHeader=false&NOW=1618966186804&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=1
   [junit4]   2> 2051433 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent [::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1|[::1]:4/twwr/m|[::1]:8/twwr/m {suggestions={quock={numFound=2,startOffset=12,endOffset=17,origFreq=0,suggestion=[{word=quick,freq=1}, {word=quote,freq=12}]},redfox={numFound=1,startOffset=19,endOffset=25,origFreq=0,suggestion=[{word=red fox,freq=14}]},jum={numFound=0,startOffset=27,endOffset=30,origFreq=0,suggestion=[]},ped={numFound=1,startOffset=32,endOffset=35,origFreq=0,suggestion=[{word=red,freq=14}]},jum ped={numFound=1,startOffset=27,endOffset=35,origFreq=0,suggestion=[{word=jumped,freq=14}]}},correctlySpelled=false,collations={collation={collationQuery=lowerfilt:(+quick +red +fox +jum +red),hits=0,misspellingsAndCorrections={quock=quick,redfox=red fox,ped=red}}},originalTerms=[quock, redfox, jum, ped]}
   [junit4]   2> 2051433 INFO  (qtp1169998344-33721) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bquock+%2Bredfox+%2Bjum+%2Bped)&shards=[::1]:6/twwr/m|https://127.0.0.1:35913/twwr/m/collection1|[::1]:4/twwr/m|[::1]:8/twwr/m&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70077 status=0 QTime=3
   [junit4]   2> 2051435 INFO  (qtp1029892502-33702) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&distrib=false&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Brodfix)&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=0
   [junit4]   2> 2051437 INFO  (qtp1169998344-33726) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&df=text&group.distributed.first=true&distrib=false&spellcheck.dictionary=default&spellcheck.dictionary=wordbreak&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70079&wt=javabin&group.field=id&group=true&qt=/spellCheckWithWordbreak&start=0&rows=10&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Brodfix)&spellcheck=true&omitHeader=false&NOW=1618966186811&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051438 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 {suggestions={rodfix={numFound=1,startOffset=12,endOffset=18,origFreq=0,suggestion=[{word=rod fix,freq=1}]}},correctlySpelled=false,collations={collation={collationQuery=lowerfilt:(+rod +fix),hits=0,misspellingsAndCorrections={rodfix=rod fix}}},originalTerms=[rodfix]}
   [junit4]   2> 2051438 INFO  (qtp1169998344-33725) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Brodfix)&shards=https://127.0.0.1:35913/twwr/m/collection1&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70079 status=0 QTime=2
   [junit4]   2> 2051441 INFO  (qtp1029892502-33703) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&distrib=false&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bson+%2Bata)&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} hits=0 status=0 QTime=1
   [junit4]   2> 2051443 INFO  (qtp1169998344-33724) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&df=text&group.distributed.first=true&distrib=false&spellcheck.dictionary=default&spellcheck.dictionary=wordbreak&fl=id,score&shards.purpose=2048&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&shard.url=https://127.0.0.1:35913/twwr/m/collection1&rid=127.0.0.1-70081&wt=javabin&group.field=id&group=true&qt=/spellCheckWithWordbreak&start=0&rows=10&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bson+%2Bata)&spellcheck=true&omitHeader=false&NOW=1618966186816&isShard=true&spellcheck.count=10&spellcheck.collate=true} status=0 QTime=0
   [junit4]   2> 2051443 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.h.c.SpellCheckComponent https://127.0.0.1:35913/twwr/m/collection1 {suggestions={son={numFound=0,startOffset=12,endOffset=15,origFreq=0,suggestion=[]},ata={numFound=0,startOffset=17,endOffset=20,origFreq=0,suggestion=[]},son ata={numFound=1,startOffset=12,endOffset=20,origFreq=0,suggestion=[{word=sonata,freq=1}]}},correctlySpelled=false,collations={collation={collationQuery=lowerfilt:(+sonata),hits=0,misspellingsAndCorrections={son ata=sonata}}},originalTerms=[son, ata]}
   [junit4]   2> 2051444 INFO  (qtp1169998344-33727) [    x:collection1 ] o.a.s.c.S.Request [collection1]  webapp=/twwr/m path=/spellCheckWithWordbreak params={spellcheck.collateExtendedResults=true&qt=/spellCheckWithWordbreak&fl=id,lowerfilt&spellcheck.maxCollations=1&spellcheck.maxCollationTries=0&version=2&shards.qt=/spellCheckWithWordbreak&spellcheck.extendedResults=true&q=lowerfilt:(%2Bson+%2Bata)&shards=https://127.0.0.1:35913/twwr/m/collection1&spellcheck=true&spellcheck.count=10&wt=javabin&group.field=id&group=true&spellcheck.collate=true} rid=127.0.0.1-70081 status=0 QTime=2
   [junit4]   2> 2051445 INFO  (TEST-DistributedSpellCheckComponentTest.test-seed#[8296CFFA0741DD8C]) [     ] o.a.s.SolrTestCaseJ4 ###Ending test
   [junit4]   2> 2051445 INFO  (closeThreadPool-21102-thread-2) [     ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1080964748
   [junit4]   2> 2051463 INFO  (coreCloseExecutor-21105-thread-1) [     ] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@68bc60ee
   [junit4]   2> 2051463 INFO  (coreCloseExecutor-21105-thread-1) [     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1 tag=SolrCore@68bc60ee
   [junit4] 

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

j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7b1294b2{/twwr/m,null,STOPPED}
   [junit4]   2> 2068713 INFO  (closeThreadPool-21260-thread-6) [     ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2068714 INFO  (closeThreadPool-21260-thread-2) [     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm tag=null
   [junit4]   2> 2068714 INFO  (closeThreadPool-21260-thread-2) [     ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33a45e31: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm/com.codahale.metrics.MetricRegistry@22454933
   [junit4]   2> 2068714 INFO  (closeThreadPool-21260-thread-2) [     ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty tag=null
   [junit4]   2> 2068714 INFO  (closeThreadPool-21260-thread-2) [     ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@fdea6c: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty/com.codahale.metrics.MetricRegistry@194e9e8
   [junit4]   2> 2068718 INFO  (closeThreadPool-21260-thread-8) [     ] o.e.j.s.AbstractConnector Stopped ServerConnector@7959feaa{SSL, (ssl, http/1.1)}{127.0.0.1:0}
   [junit4]   2> 2068720 INFO  (closeThreadPool-21260-thread-8) [     ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@158e783d{/twwr/m,null,STOPPED}
   [junit4]   2> 2068720 INFO  (closeThreadPool-21260-thread-8) [     ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> 2068722 INFO  (closeThreadPool-21260-thread-2) [     ] o.e.j.s.AbstractConnector Stopped ServerConnector@165681a0{SSL, (ssl, http/1.1)}{127.0.0.1:0}
   [junit4]   2> 2068722 INFO  (closeThreadPool-21260-thread-2) [     ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@74eb2537{/twwr/m,null,STOPPED}
   [junit4]   2> 2068722 INFO  (closeThreadPool-21260-thread-2) [     ] o.e.j.s.session node0 Stopped scavenging
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=DistributedSpellCheckComponentTest -Dtests.method=test -Dtests.seed=8296CFFA0741DD8C -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=en-IN -Dtests.timezone=Asia/Nicosia -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   21.0s J0 | DistributedSpellCheckComponentTest.test <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:46133/twwr/m/collection1: org.apache.solr.client.solrj.SolrServerException: java.lang.ArithmeticException: / by zero
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([8296CFFA0741DD8C:AC2F020A9BDB074]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:681)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:266)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:214)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1003)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:1018)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.queryServer(BaseDistributedSearchTestCase.java:625)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:677)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:655)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.query(BaseDistributedSearchTestCase.java:634)
   [junit4]    > 	at org.apache.solr.handler.component.DistributedSpellCheckComponentTest.test(DistributedSpellCheckComponentTest.java:149)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1117)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1061)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J0/temp/solr.handler.component.DistributedSpellCheckComponentTest_8296CFFA0741DD8C-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene87): {start1=PostingsFormat(name=LuceneVarGapFixedInterval), multiDefault=PostingsFormat(name=MockRandom), _root_=FST50, lowerfilt1and2=PostingsFormat(name=MockRandom), end4=PostingsFormat(name=LuceneVarGapFixedInterval), end3=PostingsFormat(name=MockRandom), end2=Lucene84, end1=FST50, lowerfilt=PostingsFormat(name=MockRandom), gram1=FST50, id=Lucene84, gram2=Lucene84, gram3=PostingsFormat(name=MockRandom), start3=Lucene84, gram4=PostingsFormat(name=LuceneVarGapFixedInterval), start2=PostingsFormat(name=MockRandom), word=FST50, start4=FST50}, docValues:{range_facet_l_dv=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Direct), range_facet_i_dv=DocValuesFormat(name=Direct), intDvoDefault=DocValuesFormat(name=Lucene80), timestamp=DocValuesFormat(name=Direct)}, maxPointsInLeafNode=1643, maxMBSortInHeap=6.256701995445615, sim=Asserting(RandomSimilarity(queryNorm=true): {}), locale=en-IN, timezone=Asia/Nicosia
   [junit4]   2> NOTE: Linux 4.15.0-112-generic amd64/Oracle Corporation 1.8.0_281 (64-bit)/cpus=4,threads=1,free=81574592,total=523239424
   [junit4]   2> NOTE: All tests run in this JVM: [OpenExchangeRatesOrgProviderTest, TestHighFrequencyDictionaryFactory, TestConfig, XmlUpdateRequestHandlerTest, ZookeeperReadAPITest, TestWithCollection, CollectionStateFormat2Test, TestReqParamsAPI, SubstringBytesRefFilterTest, OverseerSolrResponseTest, TestDocTermOrdsUninvertLimit, AuditLoggerIntegrationTest, TestStressThreadBackup, AnalyticsMergeStrategyTest, AuthToolTest, TestStressInPlaceUpdates, TestFastLRUCache, OutputWriterTest, TestCustomStream, MoveReplicaHDFSFailoverTest, PrimitiveFieldTypeTest, TestRandomRequestDistribution, TestLazyCores, TestOrdValues, ClusterStateMockUtilTest, ChaosMonkeySafeLeaderWithPullReplicasTest, DocValuesTest, BlockJoinFacetDistribTest, TestBlendedInfixSuggestions, TestRawResponseWriter, TestCloudJSONFacetSKG, SolrSlf4jReporterTest, DisMaxRequestHandlerTest, QueryEqualityTest, CoreSorterTest, ConcurrentDeleteAndCreateCollectionTest, TestSimTriggerIntegration, CoreAdminCreateDiscoverTest, DistribCursorPagingTest, SpatialFilterTest, TestStandardQParsers, AutoAddReplicasPlanActionTest, UnloadDistributedZkTest, LeaderFailureAfterFreshStartTest, MetricsHandlerTest, HdfsWriteToMultipleCollectionsTest, HdfsDirectoryFactoryTest, LeaderElectionContextKeyTest, ParsingFieldUpdateProcessorsTest, TestSegmentSorting, TestZkAclsWithHadoopAuth, ShardRoutingCustomTest, TestQuerySenderListener, TestPseudoReturnFields, TestHighlightDedupGrouping, TestLuceneMatchVersion, TestFieldCacheSortRandom, FullHLLTest, CreateCollectionCleanupTest, SolrTestCaseJ4Test, FuzzySearchTest, TestTolerantUpdateProcessorCloud, GraphQueryTest, TestSolrCoreSnapshots, TestLuceneIndexBackCompat, StatsReloadRaceTest, OverriddenZkACLAndCredentialsProvidersTest, DistributedFacetSimpleRefinementLongTailTest, CollectionTooManyReplicasTest, LocalFSCloudIncrementalBackupTest, TestInPlaceUpdateWithRouteField, RestoreTriggerStateTest, TestIncrementalCoreBackup, SegmentsInfoRequestHandlerTest, MoreLikeThisComponentTest, TestSubQueryTransformerCrossCore, DistributedSuggestComponentTest, TestImplicitCoreProperties, TemplateUpdateProcessorTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, PingRequestHandlerTest, SolrIndexSplitterTest, TestNumericTokenStream, TestTextField, TestExclusionRuleCollectionAccess, TermVectorComponentTest, AggValueSourceTest, UUIDUpdateProcessorFallbackTest, BufferStoreTest, AnalysisErrorHandlingTest, DistanceUnitsTest, DistributedExpandComponentTest, TestFieldTypeResource, TestCSVLoader, TestSchemaVersionResource, TestPerFieldSimilarityWithDefaultOverride, DocumentAnalysisRequestHandlerTest, RecoveryZkTest, TestLocalFSCloudBackupRestore, DocumentBuilderTest, TestSimClusterStateProvider, SliceStateTest, ScriptEngineTest, TestSolrCloudWithDelegationTokens, SearchRateTriggerIntegrationTest, HdfsBasicDistributedZk2Test, HdfsNNFailoverTest, BackupIdTest, TestCloudConsistency, SparseHLLTest, TestSimpleTrackingShardHandler, BasicAuthStandaloneTest, TestJsonFacets, TestSolrIndexConfig, TestPostingsSolrHighlighter, ResponseLogComponentTest, ConnectionReuseTest, AliasIntegrationTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, DistributedVersionInfoTest, HttpPartitionOnCommitTest, MetricsHistoryIntegrationTest, MetricsHistoryWithAuthIntegrationTest, MigrateRouteKeyTest, NodeMutatorTest, OutOfBoxZkACLAndCredentialsProvidersTest, PackageManagerCLITest, PeerSyncReplicationTest, TestCloudRecovery, TestConfigSetsAPI, TestDeleteCollectionOnDownNodes, TestDistribDocBasedVersion, TestLockTree, TestOnReconnectListenerSupport, TestQueryingOnDownCollection, TestRandomFlRTGCloud, ZkSolrClientTest, TestHdfsCloudBackupRestore, MetricTriggerIntegrationTest, MetricTriggerTest, NodeAddedTriggerIntegrationTest, NodeLostTriggerIntegrationTest, NodeLostTriggerTest, TriggerCooldownIntegrationTest, CdcrBidirectionalTest, CdcrBootstrapTest, HdfsTlogReplayBufferedWhileIndexingTest, ZkStateReaderTest, RulesTest, TestBackupRepositoryFactory, TestBadConfig, TestCorePropertiesReload, TestSimpleTextCodec, TestSolrDeletionPolicy1, TestSolrDeletionPolicy2, TestSnapshotCoreBackup, TestSolrConfigHandlerCloud, CustomTermsComponentTest, DistributedQueryComponentCustomSortTest, DistributedSpellCheckComponentTest]
   [junit4] Completed [657/936 (1!)] on J0 in 21.25s, 1 test, 1 error <<< FAILURES!

[...truncated 51760 lines...]