You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/02/29 07:13:58 UTC
[JENKINS] Lucene-Solr-master-Linux (64bit/jdk-11.0.6) - Build #
25880 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25880/
Java: 64bit/jdk-11.0.6 -XX:+UseCompressedOops -XX:+UseParallelGC
1 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:44771/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:44771/solr/.system]
at __randomizedtesting.SeedInfo.seed([805C4A68FD8B3CC8:F0A9E9C19D4395BE]:0)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:345)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1143)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:906)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:838)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207)
at org.apache.solr.cloud.SystemCollectionCompatTest.setupSystemCollection(SystemCollectionCompatTest.java:118)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:976)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:44771/solr/.system
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:676)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:368)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:296)
... 43 more
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
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:564)
... 47 more
Build Log:
[...truncated 13683 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 273257 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 273257 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/data-dir-72-001
[junit4] 2> 273257 WARN (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=23 numCloses=23
[junit4] 2> 273257 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 273257 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 273257 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 273258 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001
[junit4] 2> 273258 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 273258 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 273258 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 273358 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44863
[junit4] 2> 273358 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:44863
[junit4] 2> 273358 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44863
[junit4] 2> 273358 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44863
[junit4] 2> 273359 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273360 INFO (zkConnectionManagerCallback-2242-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273360 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273365 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273366 INFO (zkConnectionManagerCallback-2244-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273366 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273366 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273367 INFO (zkConnectionManagerCallback-2246-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273367 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 273469 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 273472 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 273472 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 273472 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@27d9f39d{/solr,null,AVAILABLE}
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@68edfcf7{/solr,null,AVAILABLE}
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1a403531{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:38059}
[junit4] 2> 273473 INFO (jetty-launcher-2247-thread-2) [ ] o.e.j.s.Server Started @273501ms
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=38059}
[junit4] 2> 273474 ERROR (jetty-launcher-2247-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-29T06:45:21.571185Z
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@707da680{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:44771}
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.e.j.s.Server Started @273502ms
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=44771}
[junit4] 2> 273474 ERROR (jetty-launcher-2247-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-29T06:45:21.571650Z
[junit4] 2> 273474 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273475 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273475 INFO (zkConnectionManagerCallback-2249-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273475 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273475 INFO (zkConnectionManagerCallback-2251-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273475 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273475 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 273475 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 273579 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 273579 WARN (jetty-launcher-2247-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@52f596d6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273579 WARN (jetty-launcher-2247-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@52f596d6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273580 WARN (jetty-launcher-2247-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@8917127[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273580 WARN (jetty-launcher-2247-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@8917127[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273581 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44863/solr
[junit4] 2> 273581 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273582 INFO (zkConnectionManagerCallback-2258-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273582 INFO (jetty-launcher-2247-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273679 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 273679 WARN (jetty-launcher-2247-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7827737[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273679 WARN (jetty-launcher-2247-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7827737[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273680 WARN (jetty-launcher-2247-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@34705ff6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273680 WARN (jetty-launcher-2247-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@34705ff6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 273681 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44863/solr
[junit4] 2> 273681 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273682 INFO (zkConnectionManagerCallback-2265-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273682 INFO (jetty-launcher-2247-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273779 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273780 INFO (zkConnectionManagerCallback-2267-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273780 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273800 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38059_solr
[junit4] 2> 273800 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.Overseer Overseer (id=72095613418930183-127.0.0.1:38059_solr-n_0000000000) starting
[junit4] 2> 273801 INFO (OverseerStateUpdate-72095613418930183-127.0.0.1:38059_solr-n_0000000000) [n:127.0.0.1:38059_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:38059_solr
[junit4] 2> 273801 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38059_solr
[junit4] 2> 273802 INFO (zkCallback-2266-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 273802 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 273802 WARN (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_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> 273809 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 273823 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38059.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273829 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38059.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273829 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_38059.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273829 INFO (jetty-launcher-2247-thread-2) [n:127.0.0.1:38059_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node2/.
[junit4] 2> 273879 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273880 INFO (zkConnectionManagerCallback-2273-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273880 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273881 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 273882 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:44771_solr as DOWN
[junit4] 2> 273882 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 273882 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44771_solr
[junit4] 2> 273883 INFO (zkCallback-2266-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 273883 INFO (zkCallback-2272-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 273883 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 273883 WARN (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_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> 273889 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 273897 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273901 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273902 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 273902 INFO (jetty-launcher-2247-thread-1) [n:127.0.0.1:44771_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/.
[junit4] 2> 273914 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 273914 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273915 INFO (zkConnectionManagerCallback-2282-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273915 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273915 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 273916 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44863/solr ready
[junit4] 2> 273927 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 273928 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 273929 INFO (zkConnectionManagerCallback-2287-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 273929 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 273929 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 273930 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44863/solr ready
[junit4] 2> 273931 INFO (qtp344447441-7577) [n:127.0.0.1:38059_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 273934 INFO (qtp344447441-7577) [n:127.0.0.1:38059_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 273935 INFO (qtp344447441-7577) [n:127.0.0.1:38059_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:44771_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 273937 INFO (OverseerCollectionConfigSetProcessor-72095613418930183-127.0.0.1:38059_solr-n_0000000000) [n:127.0.0.1:38059_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 273937 INFO (OverseerThreadFactory-3217-thread-2-processing-n:127.0.0.1:38059_solr) [n:127.0.0.1:38059_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 274039 WARN (OverseerThreadFactory-3217-thread-2-processing-n:127.0.0.1:38059_solr) [n:127.0.0.1:38059_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection .system 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> 274040 INFO (OverseerStateUpdate-72095613418930183-127.0.0.1:38059_solr-n_0000000000) [n:127.0.0.1:38059_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44771/solr",
[junit4] 2> "node_name":"127.0.0.1:44771_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 274041 INFO (OverseerStateUpdate-72095613418930183-127.0.0.1:38059_solr-n_0000000000) [n:127.0.0.1:38059_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:44771/solr",
[junit4] 2> "node_name":"127.0.0.1:44771_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 274242 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 274243 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr x:.system_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 274246 WARN (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
[junit4] 2> 274246 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 274247 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 274254 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 274254 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 274255 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 274255 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 274257 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 274257 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 274260 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 274260 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 274260 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n2' using configuration from configset .system, trusted=true
[junit4] 2> 274260 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 274260 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 274261 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 274261 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from configset .system, trusted=true
[junit4] 2> 274261 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 274261 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 274284 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 274284 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 274284 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 274284 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 274285 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 274285 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 274285 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 274285 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 274285 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@323c5de0[.system_shard1_replica_n1] main]
[junit4] 2> 274285 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5db6d5a2[.system_shard1_replica_n2] main]
[junit4] 2> 274286 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 274286 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 274286 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 274286 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 274286 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659852525281476608
[junit4] 2> 274287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 274287 INFO (searcherExecutor-3226-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@5db6d5a2[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 274288 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 274288 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 2 ms
[junit4] 2> 274288 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 274288 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 274288 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 274288 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659852525283573760
[junit4] 2> 274289 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 274290 INFO (searcherExecutor-3227-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@323c5de0[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 274290 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 274290 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 274790 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 274790 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 274790 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:44771/solr/.system_shard1_replica_n2/
[junit4] 2> 274790 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=http://127.0.0.1:44771/solr START replicas=[http://127.0.0.1:44771/solr/.system_shard1_replica_n1/] nUpdates=100
[junit4] 2> 274791 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n2 url=http://127.0.0.1:44771/solr DONE. We have no versions. sync failed.
[junit4] 2> 274792 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 274792 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 274792 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] 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> 274792 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/72095613418930184-core_node4-n_0000000000
[junit4] 2> 274792 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:44771/solr/.system_shard1_replica_n2/ shard1
[junit4] 2> 274893 INFO (zkCallback-2272-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 274894 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 274895 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=653
[junit4] 2> 274996 INFO (zkCallback-2272-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 274996 INFO (zkCallback-2272-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 275293 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1050
[junit4] 2> 275293 INFO (qtp344447441-7577) [n:127.0.0.1:38059_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 275393 INFO (zkCallback-2272-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 275393 INFO (zkCallback-2272-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 275393 INFO (zkCallback-2266-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 275393 INFO (qtp344447441-7577) [n:127.0.0.1:38059_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:44771_solr&wt=javabin&version=2} status=0 QTime=1458
[junit4] 2> 275393 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[805C4A68FD8B3CC8]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 275397 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=1, core_node4=1}, version=2}
[junit4] 2> 275400 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:44771/solr/.system_shard1_replica_n2/&wt=javabin&version=2}{add=[1708fb141a4Taem52f9lnma1tpvk3z9skj2cr (1659852526445395968)]} 0 0
[junit4] 2> 275400 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1708fb141a4Taem52f9lnma1tpvk3z9skj2cr (1659852526445395968)]} 0 4
[junit4] 2> 275401 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659852526450638848,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 275401 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1602d538 commitCommandVersion:1659852526450638848
[junit4] 2> 275402 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659852526451687424,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 275402 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@34776f78 commitCommandVersion:1659852526451687424
[junit4] 2> 275403 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2aa10e25[.system_shard1_replica_n1] main]
[junit4] 2> 275403 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6cdd79a1[.system_shard1_replica_n2] main]
[junit4] 2> 275403 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 275403 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 275404 INFO (searcherExecutor-3226-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@6cdd79a1[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582958723499, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-40-generic}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 275405 INFO (searcherExecutor-3227-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@2aa10e25[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582958723499, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-40-generic}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 275405 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:44771/solr/.system_shard1_replica_n2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 275405 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={_stateVer_=.system:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 4
[junit4] 2> 275406 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275407 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275408 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275410 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 275411 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 275413 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 275414 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 275415 INFO (Thread-1673) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n2
[junit4] 2> 275416 INFO (Thread-1673) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n2
[junit4] 2> 275418 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 275428 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 275430 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 275430 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 275453 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_44771.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@198ffb03
[junit4] 2> 275453 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 275472 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 275472 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1385cdb3[.system_shard1_replica_n2] main]
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275474 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 275476 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 275476 INFO (searcherExecutor-3236-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@1385cdb3[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582958723499, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-40-generic}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 275477 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@203e6f51[.system_shard1_replica_n2] main]
[junit4] 2> 275477 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 275478 INFO (searcherExecutor-3236-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@203e6f51[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.vendor=AdoptOpenJDK, os=Linux, timestamp=1582958723499, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-40-generic}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 275479 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275479 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275479 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275479 INFO (Thread-1673) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 275479 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275480 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275480 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275480 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275480 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275480 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275480 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275480 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275480 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275481 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275481 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275481 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275481 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275481 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275481 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275481 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275482 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275482 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275482 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275482 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275482 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275482 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275482 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275482 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275482 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275483 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275483 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275483 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275483 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275483 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275483 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275483 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275483 INFO (Thread-1673) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 275483 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275484 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275484 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275484 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275484 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275484 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275484 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275484 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275484 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275484 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275485 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275485 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275485 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275485 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275485 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275485 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275485 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275485 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275485 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275485 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275485 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275485 INFO (Thread-1673) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 275485 INFO (Thread-1673) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 275486 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275486 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275486 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275486 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275486 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275486 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275486 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275486 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275486 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275487 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275487 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275487 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275487 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275487 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275487 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275487 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275487 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275487 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275487 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275487 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275488 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275488 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275488 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275488 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275488 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275488 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 275488 INFO (qtp2126141223-7586) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 275488 ERROR (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 275488 INFO (qtp2126141223-7595) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 275488 IN
[...truncated too long message...]
:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:44771/solr/.system_shard1_replica_n1
[junit4] 2> 409284 WARN (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:44771/solr/.system_shard1_replica_n1
[junit4] 2> 410312 WARN (managedSchemaExecutor-3240-thread-1-processing-n:127.0.0.1:44771_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:44771/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:44771/solr/.system_shard1_replica_n1
[junit4] 2> 411278 INFO (httpUriRequest-324857-thread-1-processing-x:.system_shard1_replica_n2 r:core_node4 n:127.0.0.1:44771_solr http:////127.0.0.1:44771//solr//.system_shard1_replica_n1 c:.system s:shard1) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.h.i.e.RetryExec I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:44771: Socket closed
[junit4] 2> 411278 INFO (httpUriRequest-324857-thread-1-processing-x:.system_shard1_replica_n2 r:core_node4 n:127.0.0.1:44771_solr http:////127.0.0.1:44771//solr//.system_shard1_replica_n1 c:.system s:shard1) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.h.i.e.RetryExec Retrying request to {}->http://127.0.0.1:44771
[junit4] 2> 411286 WARN (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Core core_node4 was interrupted waiting for schema version 2 to propagate to 1 replicas for collection .system
[junit4] 2> 411286 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Took 135809.0ms for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 411287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=135877
[junit4] 2> 411287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@7ba68953
[junit4] 2> 411287 WARN (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.SolrMetricManager Interrupted while trying to obtain lock to modify reporters registry: solr.core..system.shard1.replica_n2
[junit4] 2> 411287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection..system.shard1.leader, tag=SolrCore@7ba68953
[junit4] 2> 411287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 411287 INFO (qtp2126141223-7585) [n:127.0.0.1:44771_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@c2116b5 commitCommandVersion:0
[junit4] 2> 411289 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 411491 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 5 /solr/collections/.system/terms/shard1
[junit4] 2> 4 /solr/configs/.system/managed-schema
[junit4] 2> 2 /solr/configs/.system
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/collections/.system/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 16 /solr/collections/.system/state.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/overseer/queue
[junit4] 2> 18 /solr/collections
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 11 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 411492 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:44863
[junit4] 2> 411492 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44863
[junit4] 2> 411492 INFO (SUITE-SystemCollectionCompatTest-seed#[805C4A68FD8B3CC8]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44863
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_805C4A68FD8B3CC8-001
[junit4] 2> Feb 29, 2020 6:47:39 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {id=PostingsFormat(name=Direct), type=FST50}, docValues:{timestamp_l=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Asserting), time_l=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=773, maxMBSortInHeap=7.473056453346475, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1bac1832), locale=mer-KE, timezone=Asia/Krasnoyarsk
[junit4] 2> NOTE: Linux 5.3.0-40-generic amd64/AdoptOpenJDK 11.0.6 (64-bit)/cpus=16,threads=1,free=166426752,total=439353344
[junit4] 2> NOTE: All tests run in this JVM: [HttpPartitionTest, CreateRoutedAliasTest, TestZkChroot, WrapperMergePolicyFactoryTest, MultiThreadedOCPTest, OverseerModifyCollectionTest, NodeAddedTriggerIntegrationTest, TestOrdValues, TestQueryingOnDownCollection, DeleteStatusTest, TestSimUtils, TestSolrCoreProperties, PeerSyncWithLeaderTest, TermsComponentTest, TestConfigOverlay, SliceStateTest, V2StandaloneTest, DistributedFacetSimpleRefinementLongTailTest, TestRawTransformer, TestIBSimilarityFactory, TestCorePropertiesReload, ZookeeperStatusHandlerTest, TestLuceneIndexBackCompat, DocumentAnalysisRequestHandlerTest, TestMissingGroups, TestSuggestSpellingConverter, IndexSchemaRuntimeFieldTest, TestReplicationHandler, DOMUtilTest, ConcurrentDeleteAndCreateCollectionTest, TaggingAttributeTest, ActionThrottleTest, TestFieldCacheSortRandom, TestGroupingSearch, TestExtendedDismaxParser, PrimUtilsTest, TestCrossCoreJoin, TestSQLHandlerNonCloud, PolyFieldTest, PKIAuthenticationIntegrationTest, ScheduledMaintenanceTriggerTest, TestSimComputePlanAction, DocValuesNotIndexedTest, IgnoreLargeDocumentProcessorFactoryTest, SchemaApiFailureTest, UUIDUpdateProcessorFallbackTest, TestSolrConfigHandler, RemoteQueryErrorTest, MigrateRouteKeyTest, TestManagedSchema, SignificantTermsQParserPluginTest, TestAnalyzeInfixSuggestions, DistributedSpellCheckComponentTest, SystemCollectionCompatTest]
[junit4] Completed [270/905 (1!)] on J0 in 138.36s, 1 test, 1 error <<< FAILURES!
[...truncated 54773 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25880/consoleText
[repro] Revision: 30944d35207cb3ca4f6522f354437b050a7c5cc1
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=SystemCollectionCompatTest -Dtests.method=testBackCompat -Dtests.seed=805C4A68FD8B3CC8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mer-KE -Dtests.timezone=Asia/Krasnoyarsk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] SystemCollectionCompatTest
[repro] ant compile-test
[...truncated 3128 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.SystemCollectionCompatTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=805C4A68FD8B3CC8 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=mer-KE -Dtests.timezone=Asia/Krasnoyarsk -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 81 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.SystemCollectionCompatTest
[repro] Exiting with code 0
[...truncated 43 lines...]
[JENKINS-Experimental-GC] Lucene-Solr-master-Linux
(64bit/jdk-13.0.2) - Build # 25881 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25881/
Java: 64bit/jdk-13.0.2 -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC -XX:ShenandoahCodeRootsStyle=1
1 tests failed.
FAILED: org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast
Error Message:
Request should fail after trying all replica nodes once
Stack Trace:
junit.framework.AssertionFailedError: Request should fail after trying all replica nodes once
at __randomizedtesting.SeedInfo.seed([5A108D9A77BE55CE:89CDA430D08F3CB2]:0)
at org.apache.lucene.util.LuceneTestCase.expectThrows(LuceneTestCase.java:2750)
at org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast(TestQueryingOnDownCollection.java:91)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:567)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:830)
Build Log:
[...truncated 13391 lines...]
[junit4] Suite: org.apache.solr.cloud.TestQueryingOnDownCollection
[junit4] 2> 312590 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 312590 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 312591 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/data-dir-29-001
[junit4] 2> 312591 WARN (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 312591 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 312591 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 312592 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001
[junit4] 2> 312592 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 312593 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 312593 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 312693 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44309
[junit4] 2> 312693 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:44309
[junit4] 2> 312693 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44309
[junit4] 2> 312693 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44309
[junit4] 2> 312710 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 312737 INFO (zkConnectionManagerCallback-1430-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 312737 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 312754 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 312766 INFO (zkConnectionManagerCallback-1432-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 312766 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 312766 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 312770 INFO (zkConnectionManagerCallback-1434-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 312770 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 13.0.2+8
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 13.0.2+8
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 312937 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 13.0.2+8
[junit4] 2> 312991 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 312991 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 312991 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 313005 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 313005 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 313005 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 313009 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 313009 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 313009 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 313013 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6fd43017{/solr,null,AVAILABLE}
[junit4] 2> 313013 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3b840a8d{/solr,null,AVAILABLE}
[junit4] 2> 313013 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6acdbcb1{/solr,null,AVAILABLE}
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3479c9bf{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:45831}
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.e.j.s.Server Started @313048ms
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45831}
[junit4] 2> 313037 ERROR (jetty-launcher-1435-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@77987bb2{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:46269}
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-3) [ ] o.e.j.s.Server Started @313049ms
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46269}
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 313037 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-29T08:48:29.941950Z
[junit4] 2> 313038 ERROR (jetty-launcher-1435-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-29T08:48:29.942102Z
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7f72c6d1{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:42517}
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.e.j.s.Server Started @313049ms
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42517}
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313038 ERROR (jetty-launcher-1435-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 313038 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-29T08:48:29.942922Z
[junit4] 2> 313041 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313071 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313073 INFO (zkConnectionManagerCallback-1439-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313073 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313073 INFO (zkConnectionManagerCallback-1438-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313073 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313073 INFO (zkConnectionManagerCallback-1441-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313073 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313073 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 313073 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 313077 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 313179 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 313181 WARN (jetty-launcher-1435-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@70fe1ec9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313181 WARN (jetty-launcher-1435-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@70fe1ec9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313183 WARN (jetty-launcher-1435-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@656a9f78[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313183 WARN (jetty-launcher-1435-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@656a9f78[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313184 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44309/solr
[junit4] 2> 313185 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313186 INFO (zkConnectionManagerCallback-1448-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313186 INFO (jetty-launcher-1435-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313279 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 313288 WARN (jetty-launcher-1435-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@597bb271[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313288 WARN (jetty-launcher-1435-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@597bb271[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313290 WARN (jetty-launcher-1435-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@37e90b50[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313290 WARN (jetty-launcher-1435-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@37e90b50[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313291 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44309/solr
[junit4] 2> 313296 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313296 INFO (zkConnectionManagerCallback-1455-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313296 INFO (jetty-launcher-1435-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313380 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 313381 WARN (jetty-launcher-1435-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@7d37ff09[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313381 WARN (jetty-launcher-1435-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@7d37ff09[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313385 WARN (jetty-launcher-1435-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6fb9594f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313385 WARN (jetty-launcher-1435-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6fb9594f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 313386 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44309/solr
[junit4] 2> 313389 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313390 INFO (zkConnectionManagerCallback-1462-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313390 INFO (jetty-launcher-1435-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313480 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313481 INFO (zkConnectionManagerCallback-1464-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313481 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313537 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45831_solr
[junit4] 2> 313537 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.Overseer Overseer (id=72096097609056265-127.0.0.1:45831_solr-n_0000000000) starting
[junit4] 2> 313539 INFO (OverseerStateUpdate-72096097609056265-127.0.0.1:45831_solr-n_0000000000) [n:127.0.0.1:45831_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:45831_solr
[junit4] 2> 313540 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45831_solr
[junit4] 2> 313541 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 313541 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 313541 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 313541 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 313554 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 313570 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45831.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313575 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45831.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313575 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45831.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313576 INFO (jetty-launcher-1435-thread-1) [n:127.0.0.1:45831_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node1/.
[junit4] 2> 313580 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313585 INFO (zkConnectionManagerCallback-1470-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313585 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313587 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 313589 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:42517_solr as DOWN
[junit4] 2> 313589 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 313589 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42517_solr
[junit4] 2> 313590 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 313590 INFO (zkCallback-1469-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 313591 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 313591 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 313591 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 313597 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 313609 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42517.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313614 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42517.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313614 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42517.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313615 INFO (jetty-launcher-1435-thread-2) [n:127.0.0.1:42517_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node2/.
[junit4] 2> 313680 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313681 INFO (zkConnectionManagerCallback-1476-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313681 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313683 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 313685 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:46269_solr as DOWN
[junit4] 2> 313685 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 313685 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46269_solr
[junit4] 2> 313686 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 313686 INFO (zkCallback-1469-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 313686 INFO (zkCallback-1475-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 313687 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 313687 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 313687 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 313693 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 313706 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46269.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313713 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46269.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313713 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46269.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 313714 INFO (jetty-launcher-1435-thread-3) [n:127.0.0.1:46269_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node3/.
[junit4] 2> 313737 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=3
[junit4] 2> 313737 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 313739 INFO (zkConnectionManagerCallback-1485-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 313739 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 313739 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 313740 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44309/solr ready
[junit4] 2> 313780 INFO (TEST-TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast-seed#[5A108D9A77BE55CE]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testQueryToDownCollectionShouldFailFast
[junit4] 2> 313805 INFO (qtp2072191620-5120) [n:127.0.0.1:45831_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=infected&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 313807 INFO (OverseerThreadFactory-2105-thread-1-processing-n:127.0.0.1:45831_solr) [n:127.0.0.1:45831_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection infected
[junit4] 2> 313913 INFO (OverseerStateUpdate-72096097609056265-127.0.0.1:45831_solr-n_0000000000) [n:127.0.0.1:45831_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"infected",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"infected_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:46269/solr",
[junit4] 2> "node_name":"127.0.0.1:46269_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 313915 INFO (OverseerStateUpdate-72096097609056265-127.0.0.1:45831_solr-n_0000000000) [n:127.0.0.1:45831_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"infected",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"infected_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45831/solr",
[junit4] 2> "node_name":"127.0.0.1:45831_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 314157 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 314158 INFO (qtp2072191620-5122) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:46269_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 314159 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr x:infected_shard2_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=infected_shard2_replica_n2&action=CREATE&numShards=2&collection=infected&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 314159 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr x:infected_shard2_replica_n2 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 314168 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 314169 INFO (qtp945985781-5131) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:46269_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 314169 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr x:infected_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=infected_shard1_replica_n1&action=CREATE&numShards=2&collection=infected&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 314177 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 314177 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 314187 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.IndexSchema [infected_shard2_replica_n2] Schema name=minimal
[junit4] 2> 314188 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.IndexSchema [infected_shard1_replica_n1] Schema name=minimal
[junit4] 2> 314191 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 314191 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'infected_shard2_replica_n2' using configuration from configset conf, trusted=true
[junit4] 2> 314192 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 314192 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45831.solr.core.infected.shard2.replica_n2' (registry 'solr.core.infected.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 314192 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'infected_shard1_replica_n1' using configuration from configset conf, trusted=true
[junit4] 2> 314192 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [[infected_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node1/infected_shard2_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node1/./infected_shard2_replica_n2/data/]
[junit4] 2> 314192 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46269.solr.core.infected.shard1.replica_n1' (registry 'solr.core.infected.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4ffcd71e
[junit4] 2> 314193 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [[infected_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node3/infected_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001/tempDir-001/node3/./infected_shard1_replica_n1/data/]
[junit4] 2> 314281 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 314281 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 314282 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 314282 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 314283 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@38d60239[infected_shard1_replica_n1] main]
[junit4] 2> 314285 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 314285 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 314285 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 314286 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659860273007165440
[junit4] 2> 314288 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 314288 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 314290 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 314290 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 314291 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@27c1ab99[infected_shard2_replica_n2] main]
[junit4] 2> 314293 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 314295 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 314296 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 314297 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659860273018699776
[junit4] 2> 314297 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 314297 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/infected/leaders/shard1
[junit4] 2> 314299 INFO (searcherExecutor-2118-thread-1-processing-n:127.0.0.1:45831_solr x:infected_shard2_replica_n2 c:infected s:shard2 r:core_node4) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] Registered new searcher Searcher@27c1ab99[infected_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:46269/solr/infected_shard1_replica_n1/
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy https://127.0.0.1:46269/solr/infected_shard1_replica_n1/ has no replicas
[junit4] 2> 314300 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/infected/leaders/shard1/leader after winning as /collections/infected/leader_elect/shard1/election/72096097609056267-core_node3-n_0000000000
[junit4] 2> 314302 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 314302 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/infected/leaders/shard2
[junit4] 2> 314302 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:46269/solr/infected_shard1_replica_n1/ shard1
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45831/solr/infected_shard2_replica_n2/
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy https://127.0.0.1:45831/solr/infected_shard2_replica_n2/ has no replicas
[junit4] 2> 314305 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/infected/leaders/shard2/leader after winning as /collections/infected/leader_elect/shard2/election/72096097609056265-core_node4-n_0000000000
[junit4] 2> 314305 INFO (searcherExecutor-2119-thread-1-processing-n:127.0.0.1:46269_solr x:infected_shard1_replica_n1 c:infected s:shard1 r:core_node3) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] Registered new searcher Searcher@38d60239[infected_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 314306 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:45831/solr/infected_shard2_replica_n2/ shard2
[junit4] 2> 314408 INFO (zkCallback-1475-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314408 INFO (zkCallback-1463-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314408 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314409 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 314409 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 314412 INFO (qtp945985781-5131) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=infected_shard1_replica_n1&action=CREATE&numShards=2&collection=infected&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=242
[junit4] 2> 314414 ERROR (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.c.ZkStateReader Collection infected is not lazy or watched!
[junit4] 2> 314414 INFO (zkCallback-1475-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314417 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=infected_shard2_replica_n2&action=CREATE&numShards=2&collection=infected&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=259
[junit4] 2> 314420 INFO (qtp2072191620-5120) [n:127.0.0.1:45831_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 314511 INFO (zkCallback-1475-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314511 INFO (zkCallback-1475-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314511 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314511 INFO (zkCallback-1463-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314511 INFO (qtp2072191620-5120) [n:127.0.0.1:45831_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=infected&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=707
[junit4] 2> 314517 INFO (zkCallback-1463-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314517 INFO (zkCallback-1475-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314545 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard1 to Terms{values={core_node3=1}, version=1}
[junit4] 2> 314545 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=infected:4&wt=javabin&version=2}{add=[0 (1659860273264066560), 1 (1659860273266163712), 4 (1659860273266163713), 8 (1659860273266163714), 10 (1659860273266163715), 11 (1659860273266163716), 12 (1659860273266163717), 13 (1659860273266163718), 14 (1659860273266163719), 15 (1659860273266163720), ... (56 adds)]} 0 15
[junit4] 2> 314545 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard2 to Terms{values={core_node4=1}, version=1}
[junit4] 2> 314545 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=infected:4&wt=javabin&version=2}{add=[2 (1659860273264066560), 3 (1659860273266163712), 5 (1659860273266163713), 6 (1659860273266163714), 7 (1659860273266163715), 9 (1659860273266163716), 17 (1659860273266163717), 18 (1659860273266163718), 19 (1659860273266163719), 21 (1659860273266163720), ... (44 adds)]} 0 15
[junit4] 2> 314640 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659860273378361344,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 314640 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@3cc3e55c commitCommandVersion:1659860273378361344
[junit4] 2> 314664 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5173eb[infected_shard2_replica_n2] main]
[junit4] 2> 314665 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 314666 INFO (searcherExecutor-2118-thread-1-processing-n:127.0.0.1:45831_solr x:infected_shard2_replica_n2 c:infected s:shard2 r:core_node4) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] Registered new searcher Searcher@5173eb[infected_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C44:[diagnostics={os.version=5.3.0-40-generic, os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582966111560, java.version=13.0.2, java.vm.version=13.0.2+8, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=13.0.2+8}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 314667 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:46269/solr/infected_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 27
[junit4] 2> 314668 INFO (qtp945985781-5132) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659860273407721472,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 314668 INFO (qtp945985781-5132) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5cc7b53f commitCommandVersion:1659860273407721472
[junit4] 2> 314676 INFO (qtp945985781-5132) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3f090ffa[infected_shard1_replica_n1] main]
[junit4] 2> 314677 INFO (qtp945985781-5132) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 314679 INFO (searcherExecutor-2119-thread-1-processing-n:127.0.0.1:46269_solr x:infected_shard1_replica_n1 c:infected s:shard1 r:core_node3) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] Registered new searcher Searcher@3f090ffa[infected_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C56:[diagnostics={os.version=5.3.0-40-generic, os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582966111577, java.version=13.0.2, java.vm.version=13.0.2+8, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=13.0.2+8}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 314681 INFO (qtp945985781-5132) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=infected:4&commit=true&wt=javabin&version=2}{commit=} 0 132
[junit4] 2> 314684 INFO (zkCallback-1475-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314684 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314684 INFO (zkCallback-1475-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314684 INFO (zkCallback-1463-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314684 INFO (zkCallback-1475-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314684 INFO (zkCallback-1463-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 314751 INFO (qtp2072191620-5162) [n:127.0.0.1:45831_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 314752 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:45831_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 314753 INFO (qtp2072191620-5122) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.S.Request [infected_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=https://127.0.0.1:45831/solr/infected_shard2_replica_n2/&rows=0&version=2&q=*:*&omitHeader=false&NOW=1582966111599&isShard=true&wt=javabin} hits=44 status=0 QTime=0
[junit4] 2> 314754 INFO (qtp2072191620-5162) [n:127.0.0.1:45831_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 314755 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:45831_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 314755 INFO (qtp945985781-5127) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.S.Request [infected_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=https://127.0.0.1:46269/solr/infected_shard1_replica_n1/&rows=0&version=2&q=*:*&omitHeader=false&NOW=1582966111599&isShard=true&wt=javabin} hits=56 status=0 QTime=0
[junit4] 2> 314756 INFO (qtp2072191620-5128) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.S.Request [infected_shard2_replica_n2] webapp=/solr path=/select params={q=*:*&rows=0&wt=javabin&version=2} hits=100 status=0 QTime=61
[junit4] 2> 314758 INFO (TEST-TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast-seed#[5A108D9A77BE55CE]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testQueryToDownCollectionShouldFailFast
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestQueryingOnDownCollection -Dtests.method=testQueryToDownCollectionShouldFailFast -Dtests.seed=5A108D9A77BE55CE -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=SystemV/CST6 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 1.02s J0 | TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast <<<
[junit4] > Throwable #1: junit.framework.AssertionFailedError: Request should fail after trying all replica nodes once
[junit4] > at __randomizedtesting.SeedInfo.seed([5A108D9A77BE55CE:89CDA430D08F3CB2]:0)
[junit4] > at org.apache.lucene.util.LuceneTestCase.expectThrows(LuceneTestCase.java:2750)
[junit4] > at org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast(TestQueryingOnDownCollection.java:91)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:567)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:830)
[junit4] 2> 314863 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1623624873
[junit4] 2> 314863 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:45831_solr
[junit4] 2> 314863 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=123438879
[junit4] 2> 314863 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:42517_solr
[junit4] 2> 314864 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 314864 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:42517_solr as DOWN
[junit4] 2> 314864 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=35419974
[junit4] 2> 314864 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:46269_solr
[junit4] 2> 314865 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 314865 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:45831_solr as DOWN
[junit4] 2> 314867 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 314867 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:46269_solr as DOWN
[junit4] 2> 314869 INFO (coreCloseExecutor-2129-thread-1) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@7e5d3466
[junit4] 2> 314869 INFO (coreCloseExecutor-2129-thread-1) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.infected.shard2.replica_n2, tag=SolrCore@7e5d3466
[junit4] 2> 314869 INFO (coreCloseExecutor-2129-thread-1) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5218ad6a: rootName = solr_45831, domain = solr.core.infected.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.infected.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@1a40b332
[junit4] 2> 314877 INFO (coreCloseExecutor-2129-thread-1) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.infected.shard2.leader, tag=SolrCore@7e5d3466
[junit4] 2> 314878 INFO (coreCloseExecutor-2129-thread-1) [n:127.0.0.1:45831_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 314882 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 314882 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@46e4a3e: rootName = solr_42517, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3e1f9275
[junit4] 2> 314887 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 314887 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7577c72c: rootName = solr_42517, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5f106f10
[junit4] 2> 314889 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 314890 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@72c75e04: rootName = solr_42517, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@7503c6d9
[junit4] 2> 314890 INFO (jetty-closer-1488-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 314908 INFO (coreCloseExecutor-2130-thread-1) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@3d041ae8
[junit4] 2> 314908 INFO (coreCloseExecutor-2130-thread-1) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.infected.shard1.replica_n1, tag=SolrCore@3d041ae8
[junit4] 2> 314908 INFO (coreCloseExecutor-2130-thread-1) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@51f4f994: rootName = solr_46269, domain = solr.core.infected.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.infected.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@563a84b0
[junit4] 2> 314916 INFO (coreCloseExecutor-2130-thread-1) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.infected.shard1.leader, tag=SolrCore@3d041ae8
[junit4] 2> 314917 INFO (coreCloseExecutor-2130-thread-1) [n:127.0.0.1:46269_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 314920 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 314920 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@50480924: rootName = solr_45831, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@70e2c3c6
[junit4] 2> 314925 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 314925 INFO (zkCallback-1475-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 314925 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 314925 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@25d97802: rootName = solr_46269, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@4ea8192c
[junit4] 2> 314925 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 314926 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@423f74bc: rootName = solr_45831, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5f106f10
[junit4] 2> 314928 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 314928 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@246c9b7d: rootName = solr_45831, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@7503c6d9
[junit4] 2> 314928 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 314930 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 314930 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5aa058d: rootName = solr_46269, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@5f106f10
[junit4] 2> 314931 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 314931 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@40707791: rootName = solr_46269, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@7503c6d9
[junit4] 2> 314931 INFO (jetty-closer-1488-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 314934 INFO (closeThreadPool-1500-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72096097609056265-127.0.0.1:45831_solr-n_0000000000) closing
[junit4] 2> 314934 INFO (OverseerStateUpdate-72096097609056265-127.0.0.1:45831_solr-n_0000000000) [n:127.0.0.1:45831_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:45831_solr
[junit4] 2> 314934 INFO (OverseerAutoScalingTriggerThread-72096097609056265-127.0.0.1:45831_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 314940 INFO (zkCallback-1463-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 314943 INFO (closeThreadPool-1500-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72096097609056265-127.0.0.1:45831_solr-n_0000000000) closing
[junit4] 2> 315026 INFO (jetty-closer-1488-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7f72c6d1{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:0}
[junit4] 2> 315026 INFO (jetty-closer-1488-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6fd43017{/solr,null,UNAVAILABLE}
[junit4] 2> 315026 INFO (jetty-closer-1488-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 315125 INFO (jetty-closer-1488-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72096097609056265-127.0.0.1:45831_solr-n_0000000000) closing
[junit4] 2> 315134 INFO (jetty-closer-1488-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3479c9bf{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:0}
[junit4] 2> 315135 INFO (jetty-closer-1488-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@3b840a8d{/solr,null,UNAVAILABLE}
[junit4] 2> 315135 INFO (jetty-closer-1488-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 315226 INFO (jetty-closer-1488-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@77987bb2{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:0}
[junit4] 2> 315227 INFO (jetty-closer-1488-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6acdbcb1{/solr,null,UNAVAILABLE}
[junit4] 2> 315227 INFO (jetty-closer-1488-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 315228 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 315431 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> 4 /solr/aliases.json
[junit4] 2> 3 /solr/packages.json
[junit4] 2> 3 /solr/collections/infected/terms/shard2
[junit4] 2> 3 /solr/collections/infected/terms/shard1
[junit4] 2> 3 /solr/security.json
[junit4] 2> 2 /solr/configs/conf
[junit4] 2> 2 /solr/collections/infected/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 24 /solr/collections/infected/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 2 /solr/overseer_elect/election/72096097609056265-127.0.0.1:45831_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 19 /solr/overseer/queue
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 8 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 315432 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:44309
[junit4] 2> 315432 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44309
[junit4] 2> 315432 INFO (SUITE-TestQueryingOnDownCollection-seed#[5A108D9A77BE55CE]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44309
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_5A108D9A77BE55CE-001
[junit4] 2> Feb 29, 2020 8:48:32 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {_root_=PostingsFormat(name=LuceneVarGapFixedInterval), id=FST50}, docValues:{_version_=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=1068, maxMBSortInHeap=5.417777337908023, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6d108580), locale=de, timezone=SystemV/CST6
[junit4] 2> NOTE: Linux 5.3.0-40-generic amd64/AdoptOpenJDK 13.0.2 (64-bit)/cpus=16,threads=1,free=374493576,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [HdfsBasicDistributedZkTest, CachingDirectoryFactoryTest, TestSuggestSpellingConverter, UUIDUpdateProcessorFallbackTest, TestExclusionRuleCollectionAccess, TestIntervalFaceting, TestDocBasedVersionConstraints, TestReplicationHandler, TestSSLRandomization, TestCloudPhrasesIdentificationComponent, TestSurroundQueryParser, HttpTriggerListenerTest, ZkControllerTest, TestGroupingSearch, AsyncCallRequestStatusResponseTest, TestSimComputePlanAction, TestLockTree, IndexSchemaRuntimeFieldTest, TestHighFrequencyDictionaryFactory, TestMissingGroups, TestSQLHandlerNonCloud, SchemaApiFailureTest, TestInPlaceUpdatesRequiredField, ZookeeperStatusHandlerTest, BasicAuthStandaloneTest, TestBulkSchemaConcurrent, DocValuesNotIndexedTest, TestLuceneIndexBackCompat, TestSubQueryTransformer, EchoParamsTest, TestQueryingOnDownCollection]
[junit4] Completed [169/905 (1!)] on J0 in 3.27s, 1 test, 1 failure <<< FAILURES!
[...truncated 55090 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25881/consoleText
[repro] Revision: c929b65c81166eba60c65fa08444cc7c97709722
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC -XX:ShenandoahCodeRootsStyle=1"
[repro] Repro line: ant test -Dtestcase=TestQueryingOnDownCollection -Dtests.method=testQueryToDownCollectionShouldFailFast -Dtests.seed=5A108D9A77BE55CE -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=SystemV/CST6 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestQueryingOnDownCollection
[repro] ant compile-test
[...truncated 3128 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.TestQueryingOnDownCollection" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseShenandoahGC -XX:ShenandoahCodeRootsStyle=1" -Dtests.seed=5A108D9A77BE55CE -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=de -Dtests.timezone=SystemV/CST6 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 81 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.TestQueryingOnDownCollection
[repro] Exiting with code 0
[...truncated 43 lines...]