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/07/19 21:43:27 UTC
[JENKINS] Lucene » Lucene-Solr-Tests-8.9 - Build # 237 - Still Unstable!
Build: https://ci-builds.apache.org/job/Lucene/job/Lucene-Solr-Tests-8.9/237/
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:33143/solr
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:33143/solr
at __randomizedtesting.SeedInfo.seed([A66D6CE332D79364]: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 14711 lines...]
[junit4] Suite: org.apache.solr.servlet.HttpSolrCallGetCoreTest
[junit4] 2> 905004 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-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.9/solr/server/solr/configsets/_default/conf'
[junit4] 2> 905004 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 905004 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/data-dir-97-001
[junit4] 2> 905005 WARN (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 905005 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 905007 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 905007 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.SolrCloudTestCase Using per-replica state
[junit4] 2> 905007 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001
[junit4] 2> 905007 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 905117 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 905117 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 905119 WARN (ZkTestServer Run Thread) [ ] o.a.z.s.ServerCnxnFactory maxCnxns is not configured, using default value 0.
[junit4] 2> 905217 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port: 43221
[junit4] 2> 905217 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:43221
[junit4] 2> 905217 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:43221
[junit4] 2> 905217 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 43221
[junit4] 2> 905221 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 905229 INFO (zkConnectionManagerCallback-9731-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 905229 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 905241 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 905249 INFO (zkConnectionManagerCallback-9733-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 905249 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 905250 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 905251 INFO (zkConnectionManagerCallback-9735-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 905251 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 905252 WARN (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker-SendThread(127.0.0.1:43221)) [ ] o.a.z.ClientCnxn An exception was thrown while closing send thread for session 0x106777e3bc40002.
[junit4] 2> => EndOfStreamException: Unable to read additional data from server sessionid 0x106777e3bc40002, 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 0x106777e3bc40002, 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> 905445 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 905445 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 905445 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.Server jetty-9.4.41.v20210516; built: 2021-05-16T23:56:28.993Z; git: 98607f93c7833e7dc59489b13f3cb0a114fb9f4c; jvm 1.8.0_291-b10
[junit4] 2> 905524 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 905524 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 905525 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 905525 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7a9d5a10{/solr,null,AVAILABLE}
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@58e76347{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:33143}
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.e.j.s.Server Started @905556ms
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, zkHost=127.0.0.1:43221/solr, hostPort=33143}
[junit4] 2> 905526 ERROR (jetty-launcher-9736-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 8.9.1
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr
[junit4] 2> 905526 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2021-07-19T20:59:32.259Z
[junit4] 2> 905527 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 905529 INFO (zkConnectionManagerCallback-9738-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 905530 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 905530 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 905534 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.SolrXmlConfig Metrics collection is disabled.
[junit4] 2> 905535 WARN (jetty-launcher-9736-thread-1-SendThread(127.0.0.1:43221)) [ ] o.a.z.ClientCnxn An exception was thrown while closing send thread for session 0x106777e3bc40003.
[junit4] 2> => EndOfStreamException: Unable to read additional data from server sessionid 0x106777e3bc40003, 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 0x106777e3bc40003, 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> 906778 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 906779 WARN (jetty-launcher-9736-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@8e79[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 906779 WARN (jetty-launcher-9736-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@8e79[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 906990 WARN (jetty-launcher-9736-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@f276377[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 906990 WARN (jetty-launcher-9736-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@f276377[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 906991 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:43221/solr
[junit4] 2> 906993 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 906994 INFO (zkConnectionManagerCallback-9749-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 906994 INFO (jetty-launcher-9736-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 907101 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 907102 INFO (zkConnectionManagerCallback-9751-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 907102 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 907185 WARN (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_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> 907190 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33143_solr
[junit4] 2> 907191 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.Overseer Overseer (id=73877827950477317-127.0.0.1:33143_solr-n_0000000000) starting
[junit4] 2> 907198 INFO (OverseerStateUpdate-73877827950477317-127.0.0.1:33143_solr-n_0000000000) [n:127.0.0.1:33143_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:33143_solr
[junit4] 2> 907198 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33143_solr
[junit4] 2> 907202 INFO (OverseerStateUpdate-73877827950477317-127.0.0.1:33143_solr-n_0000000000) [n:127.0.0.1:33143_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 907204 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 907204 WARN (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_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> 907221 INFO (jetty-launcher-9736-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1
[junit4] 2> 907240 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=1
[junit4] 2> 907241 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 907244 INFO (zkConnectionManagerCallback-9766-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 907244 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 907247 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 907248 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:43221/solr ready
[junit4] 2> 907258 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 907273 WARN (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_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> 907280 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard1_replica_n1",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907287 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard1_replica_n3",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907293 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard2_replica_n5",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907300 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard2_replica_n7",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907306 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard3_replica_n9",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907310 INFO (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "core":"collection1_shard3_replica_n11",
[junit4] 2> "node_name":"127.0.0.1:33143_solr",
[junit4] 2> "base_url":"http://127.0.0.1:33143/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> 907315 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907315 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr x:collection1_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 907316 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907316 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907317 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907321 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907322 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907343 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907343 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907343 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907345 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907346 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907346 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907346 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard1_replica_n3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard1_replica_n3/data/]
[junit4] 2> 907347 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907347 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907347 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907347 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard2_replica_n5], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard2_replica_n5/data/]
[junit4] 2> 907348 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907348 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907348 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907348 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard2_replica_n7], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard2_replica_n7/data/]
[junit4] 2> 907354 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907358 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907358 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907358 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907358 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard3_replica_n9], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard3_replica_n9/data/]
[junit4] 2> 907360 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907361 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907361 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907361 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907361 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard3_replica_n11], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard3_replica_n11/data/]
[junit4] 2> 907369 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.9.1
[junit4] 2> 907376 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=minimal
[junit4] 2> 907377 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907377 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907377 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene/Lucene-Solr-Tests-8.9/solr/build/solr-core/test/J2/temp/solr.servlet.HttpSolrCallGetCoreTest_A66D6CE332D79364-001/tempDir-001/node1/collection1_shard1_replica_n1/data/]
[junit4] 2> 907442 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907442 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907442 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907442 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907443 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907443 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907443 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907443 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907446 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907446 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907446 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907446 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907448 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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 1705748331686264832
[junit4] 2> 907449 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907449 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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 1705748331686264832
[junit4] 2> 907451 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907451 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907451 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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 1705748331688361984
[junit4] 2> 907453 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907453 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907454 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907454 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907456 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907456 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907457 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907457 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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 1705748331694653440
[junit4] 2> 907458 INFO (searcherExecutor-9772-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard2_replica_n7 c:collection1 s:shard2 r:core_node8) [n:127.0.0.1:33143_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> 907458 INFO (searcherExecutor-9770-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard2_replica_n5 c:collection1 s:shard2 r:core_node6) [n:127.0.0.1:33143_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> 907459 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907459 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907460 INFO (searcherExecutor-9778-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard1_replica_n1 c:collection1 s:shard1 r:core_node2) [n:127.0.0.1:33143_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> 907461 INFO (searcherExecutor-9774-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard3_replica_n9 c:collection1 s:shard3 r:core_node10) [n:127.0.0.1:33143_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> 907461 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907461 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node12 x:collection1_shard3_replica_n11 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907463 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907465 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907465 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907465 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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 1705748331703042048
[junit4] 2> 907465 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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_node8=0}, version=0}
[junit4] 2> 907466 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_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> 907467 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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, core_node8=0}, version=1}
[junit4] 2> 907467 INFO (qtp1444976627-15926) [n:127.0.0.1:33143_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> 907471 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907471 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907473 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 907474 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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}, version=0}
[junit4] 2> 907474 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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> 907474 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 907474 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:33143/solr/collection1_shard2_replica_n7/
[junit4] 2> 907475 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica_n7 url=http://127.0.0.1:33143/solr START replicas=[http://127.0.0.1:33143/solr/collection1_shard2_replica_n5/] nUpdates=100
[junit4] 2> 907476 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907476 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907477 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 907477 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica_n7 url=http://127.0.0.1:33143/solr DONE. We have no versions. sync failed.
[junit4] 2> 907477 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 907478 INFO (searcherExecutor-9776-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard3_replica_n11 c:collection1 s:shard3 r:core_node12) [n:127.0.0.1:33143_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> 907478 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_solr c:collection1 s:shard3 r:core_node10 x:collection1_shard3_replica_n9 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard3: total=2 found=1 timeoute in=9998ms
[junit4] 2> 907479 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907479 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907479 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907480 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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 1705748331718770688
[junit4] 2> 907482 INFO (qtp1444976627-15968) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node6 x:collection1_shard2_replica_n5 ] o.a.s.c.S.Request [collection1_shard2_replica_n5] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 907482 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 907482 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] 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> 907482 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard2/leader after winning as /collections/collection1/leader_elect/shard2/election/73877827950477317-core_node8-n_0000000000
[junit4] 2> 907484 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoute in=9998ms
[junit4] 2> 907485 INFO (searcherExecutor-9768-thread-1-processing-n:127.0.0.1:33143_solr x:collection1_shard1_replica_n3 c:collection1 s:shard1 r:core_node4) [n:127.0.0.1:33143_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> 907487 INFO (zkCallback-9750-thread-1) [ ] 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> 907487 INFO (zkCallback-9750-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> 907487 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:33143/solr/collection1_shard2_replica_n7/ shard2
[junit4] 2> 907488 INFO (zkCallback-9750-thread-3) [ ] 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> 907492 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907492 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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> 907495 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard2 r:core_node8 x:collection1_shard2_replica_n7 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 907500 INFO (zkCallback-9750-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> 907500 INFO (zkCallback-9750-thread-3) [ ] 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> 907500 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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_node2=0, core_node4=0}, version=1}
[junit4] 2> 907500 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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> 907501 INFO (zkCallback-9750-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> 907507 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={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} status=0 QTime=191
[junit4] 2> 907979 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907979 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907979 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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:33143/solr/collection1_shard3_replica_n9/
[junit4] 2> 907979 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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:33143/solr START replicas=[http://127.0.0.1:33143/solr/collection1_shard3_replica_n11/] nUpdates=100
[junit4] 2> 907979 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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:33143/solr DONE. We have no versions. sync failed.
[junit4] 2> 907980 INFO (qtp1444976627-15968) [n:127.0.0.1:33143_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> 907980 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907980 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907980 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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/73877827950477317-core_node10-n_0000000000
[junit4] 2> 907982 INFO (zkCallback-9750-thread-1) [ ] 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> 907982 INFO (zkCallback-9750-thread-3) [ ] 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> 907982 INFO (zkCallback-9750-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> 907982 INFO (zkCallback-9750-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> 907982 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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:33143/solr/collection1_shard3_replica_n9/ shard3
[junit4] 2> 907983 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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> 907985 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 907985 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 907985 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:33143/solr/collection1_shard1_replica_n1/
[junit4] 2> 907985 INFO (zkCallback-9750-thread-3) [ ] 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> 907985 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n1 url=http://127.0.0.1:33143/solr START replicas=[http://127.0.0.1:33143/solr/collection1_shard1_replica_n3/] nUpdates=100
[junit4] 2> 907985 INFO (zkCallback-9750-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> 907985 INFO (zkCallback-9750-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> 907985 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica_n1 url=http://127.0.0.1:33143/solr DONE. We have no versions. sync failed.
[junit4] 2> 907985 INFO (zkCallback-9750-thread-1) [ ] 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> 907985 INFO (qtp1444976627-15928) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node4 x:collection1_shard1_replica_n3 ] o.a.s.c.S.Request [collection1_shard1_replica_n3] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 907986 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 907986 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] 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> 907986 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/collection1/leaders/shard1/leader after winning as /collections/collection1/leader_elect/shard1/election/73877827950477317-core_node2-n_0000000000
[junit4] 2> 907987 INFO (qtp1444976627-15966) [n:127.0.0.1:33143_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=666
[junit4] 2> 907988 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:33143/solr/collection1_shard1_replica_n1/ shard1
[junit4] 2> 907988 INFO (zkCallback-9750-thread-3) [ ] 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> 907988 INFO (zkCallback-9750-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> 907988 INFO (zkCallback-9750-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> 907988 INFO (zkCallback-9750-thread-1) [ ] 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> 907989 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 907990 INFO (zkCallback-9750-thread-3) [ ] 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> 907990 INFO (zkCallback-9750-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> 907990 INFO (zkCallback-9750-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> 907990 INFO (zkCallback-9750-thread-1) [ ] 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> 907992 INFO (qtp1444976627-15927) [n:127.0.0.1:33143_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=677
[junit4] 2> 908501 INFO (zkCallback-9750-thread-3) [ ] 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> 908501 INFO (zkCallback-9750-thread-1) [ ] 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> 908501 INFO (zkCallback-9750-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> 908501 INFO (zkCallback-9750-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> 908504 INFO (qtp1444976627-15967) [n:127.0.0.1:33143_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=1182
[junit4] 2> 908506 INFO (zkCallback-9750-thread-1) [ ] 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> 908506 INFO (zkCallback-9750-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> 908506 INFO (zkCallback-9750-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> 908506 INFO (zkCallback-9750-thread-3) [ ] 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> 908508 INFO (qtp1444976627-15924) [n:127.0.0.1:33143_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=1193
[junit4] 2> 1027413 ERROR (OverseerThreadFactory-9758-thread-1-processing-n:127.0.0.1:33143_solr) [n:127.0.0.1:33143_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Error from shard: http://127.0.0.1:33143/solr
[junit4] 2> => org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:33143/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:33143/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_291]
[junit4] 2> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[?:1.8.0_291]
[junit4] 2> at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[?:1.8.0_291]
[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_291]
[junit4] 2> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_291]
[junit4] 2> at java.lang.Thread.run(Thread.java:748) [?:1.8.0_291]
[junit4] 2> Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] 2> at java.net.SocketInputStream.socketRead0(Native Method) ~[?:1.8.0_291]
[junit4] 2> at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[?:1.8.0_291]
[junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[?:1.8.0_291]
[junit4] 2> at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:1.8.0_291]
[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> 1087257 ERROR (qtp1444976627-15925) [n:127.0.0.1:33143_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:1624)
[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:1435)
[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:1594)
[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:1350)
[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:763)
[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:388)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
[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:882)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1087258 INFO (qtp1444976627-15925) [n:127.0.0.1:33143_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> 1087258 ERROR (qtp1444976627-15925) [n:127.0.0.1:33143_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:1624)
[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:1435)
[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:1594)
[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:1350)
[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:763)
[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:388)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
[junit4] 2> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
[junit4] 2> at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
[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:882)
[junit4] 2> at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
[junit4] 2> at java.lang.Thread.run(Thread.java:748)
[junit4] 2>
[junit4] 2> 1087297 INFO (jetty-closer-9803-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1499430685
[junit4] 2> 1087297 INFO (jetty-closer-9803-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:33143_solr
[junit4] 2> 1087298 INFO (jetty-closer-9803-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 1087298 INFO (jetty-closer-9803-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:33143_solr as DOWN
[junit4] 2> 1087303 INFO (zkCallback-9750-thread-7) [ ] 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> 1087305 INFO (coreCloseExecutor-9807-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.c.SolrCore [collection1_shard3_replica_n9] CLOSING SolrCore org.apache.solr.core.SolrCore@73f0b040
[junit4] 2> 1087305 INFO (coreCloseExecutor-9807-thread-2) [n:127.0.0.1:33143_solr ] o.a.s.c.SolrCore [collection1_shard2_replica_n7] CLOSING SolrCore org.apache.solr.core.SolrCore@3244ce3a
[junit4] 2> 1087305 INFO (coreCloseExecutor-9807-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard3.replica_n9 tag=SolrCore@73f0b040
[junit4] 2> 1087305 INFO (coreCloseExecutor-9807-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard3.leader tag=SolrCore@73f0b040
[junit4] 2> 1087305 INFO (coreCloseExecutor-9807-thread-2) [n:127.0.0.1:33143_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1.shard2.replica_n7 tag=SolrCore@3244ce3a
[junit4] 2> 1087305 INFO (coreCloseExecutor-9807-thread-2) [n:127.0.0.1:33143_solr ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.collection1.shard2.leader tag=SolrCore@3244ce3a
[junit4] 2> 1087306 INFO (coreCloseExecutor-9807-thread-1) [n:127.0.0.1:33143_solr ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 1087306 INFO (coreCloseExecutor-9807-thread-2) [n:127.0.0.1:33143_solr ] o.a.
[...truncated too long message...]
ion was thrown while closing send thread for session 0x106777e3bc40001.
[junit4] 2> => EndOfStreamException: Unable to read additional data from server sessionid 0x106777e3bc40001, 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 0x106777e3bc40001, 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> 1087654 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/shard2
[junit4] 2> 3 /solr/collections/collection1/terms/shard3
[junit4] 2> 3 /solr/collections/collection1/terms/shard1
[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> 6 /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> 40 /solr/collections/collection1/state.json
[junit4] 2> 8 /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> 1087657 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:43221
[junit4] 2> 1087657 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:43221
[junit4] 2> 1087657 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 43221
[junit4] 2> 1087657 INFO (SUITE-HttpSolrCallGetCoreTest-seed#[A66D6CE332D79364]-worker) [ ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> Jul 19, 2021 9:02:34 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=Lucene87, sim=Asserting(RandomSimilarity(queryNorm=false): {}), locale=zh, timezone=Etc/Universal
[junit4] 2> NOTE: Linux 5.4.0-45-generic amd64/Oracle Corporation 1.8.0_291 (64-bit)/cpus=4,threads=1,free=211232992,total=519569408
[junit4] 2> NOTE: All tests run in this JVM: [MigrateRouteKeyTest, TestSimNodeLostTrigger, TestShortCircuitedRequests, PeerSyncReplicationTest, TestLMDirichletSimilarityFactory, SpellingQueryConverterTest, TestCSVLoader, SolrLogAuditLoggerPluginTest, SolrIndexMetricsTest, DistribJoinFromCollectionTest, TestSolrCoreSnapshots, ForceLeaderTest, TestLegacyNumericRangeQueryBuilder, RemoteQueryErrorTest, TestStressLiveNodes, TestCustomStream, TestSolrCloudWithKerberosAlt, DistributedDebugComponentTest, PurgeGraphTest, RankQueryTest, TestRebalanceLeaders, OverseerStatusTest, TestPointFields, HttpTriggerListenerTest, TestClassicSimilarityFactory, TestManagedStopFilterFactory, NestedAtomicUpdateTest, DocumentAnalysisRequestHandlerTest, TestDefaultStatsCache, SolrRequestParserTest, TestSimpleTextCodec, TestSolrCloudWithHadoopAuthPlugin, SegmentsInfoRequestHandlerTest, ClusterStateUpdateTest, TestXmlQParserPlugin, TransactionLogTest, TestFieldCacheSort, TestCryptoKeys, SSLMigrationTest, CoreMergeIndexesAdminHandlerTest, HighlighterWithoutStoredIdTest, URLClassifyProcessorTest, TestSortableTextField, DeleteShardTest, ZkNodePropsTest, RootFieldTest, PluginInfoTest, CustomCollectionTest, SchemaApiFailureTest, ActionThrottleTest, CursorMarkTest, RestartWhileUpdatingTest, SolrJmxReporterTest, TestFastOutputStream, InfoHandlerTest, TestSlowCompositeReaderWrapper, BasicDistributedZk2Test, TestMultiWordSynonyms, HttpPartitionTest, TriggerEventQueueTest, ResourceLoaderTest, TestLegacyFieldCache, ZkDynamicConfigTest, HdfsBasicDistributedZkTest, ShardTermsTest, PreAnalyzedFieldTest, SynonymTokenizerTest, TestLRUStatsCache, CdcrVersionReplicationTest, TestExpandComponent, TestConfigSets, TestWriterPerf, PingRequestHandlerTest, TestSolrQueryResponse, SpellCheckComponentTest, TestJsonRangeFacets, TestIntervalFaceting, ClassificationUpdateProcessorFactoryTest, NodeMutatorTest, TestSubQueryTransformer, TestNamedUpdateProcessors, SystemCollectionCompatTest, TestTestInjection, CollectionsAPIAsyncDistributedZkTest, TestBackupRepositoryFactory, DocValuesMultiTest, ExplicitHLLTest, TestIncrementalCoreBackup, TestQuerySenderListener, ByteBuffersDirectoryFactoryTest, TestEmbeddedSolrServerConstructors, TestCursorMarkWithoutUniqueKey, BackupIdTest, TestRealTimeGet, DateMathParserTest, AutoScalingHandlerTest, TestWordDelimiterFilterFactory, TestFuzzyAnalyzedSuggestions, DistributedMLTComponentTest, StatelessScriptUpdateProcessorFactoryTest, BlockDirectoryTest, TestSolrCoreParser, MetricsConfigTest, CleanupOldIndexTest, TestDocumentBuilder, TestPullReplicaWithAuth, DeleteInactiveReplicaTest, HttpSolrCallGetCoreTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=HttpSolrCallGetCoreTest -Dtests.seed=A66D6CE332D79364 -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=zh -Dtests.timezone=Etc/Universal -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J2 | HttpSolrCallGetCoreTest (suite) <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:33143/solr
[junit4] > at __randomizedtesting.SeedInfo.seed([A66D6CE332D79364]: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 [418/939 (1!)] on J2 in 183.08s, 0 tests, 1 error <<< FAILURES!
[...truncated 54318 lines...]