You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2020/02/17 11:27:51 UTC
[JENKINS] Lucene-Solr-Tests-master - Build # 4266 - Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/4266/
1 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[https://127.0.0.1:34397/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[https://127.0.0.1:34397/solr/.system]
at __randomizedtesting.SeedInfo.seed([A303F8636388D5B3:D3F65BCA03407CC5]: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: https://127.0.0.1:34397/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 java.base/sun.security.ssl.SSLSocketInputRecord.read(SSLSocketInputRecord.java:448)
at java.base/sun.security.ssl.SSLSocketInputRecord.bytesInCompletePacket(SSLSocketInputRecord.java:68)
at java.base/sun.security.ssl.SSLSocketImpl.readApplicationRecord(SSLSocketImpl.java:1104)
at java.base/sun.security.ssl.SSLSocketImpl$AppInputStream.read(SSLSocketImpl.java:823)
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 14255 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 2885610 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/server/solr/configsets/_default/conf'
[junit4] 2> 2885611 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/data-dir-175-001
[junit4] 2> 2885611 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 2885612 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 2885612 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2885613 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001
[junit4] 2> 2885613 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2885614 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2885614 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2885714 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:45396
[junit4] 2> 2885714 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:45396
[junit4] 2> 2885714 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:45396
[junit4] 2> 2885714 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 45396
[junit4] 2> 2885715 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2885717 INFO (zkConnectionManagerCallback-11742-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2885717 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2885719 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2885720 INFO (zkConnectionManagerCallback-11744-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2885720 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2885721 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2885722 INFO (zkConnectionManagerCallback-11746-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2885722 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2885830 WARN (jetty-launcher-11747-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2885830 WARN (jetty-launcher-11747-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2885830 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6f9c78ba{/solr,null,AVAILABLE}
[junit4] 2> 2885832 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4092fa74{/solr,null,AVAILABLE}
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5f260c7f{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:34397}
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2f65a893{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:35433}
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-1) [ ] o.e.j.s.Server Started @2885931ms
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-2) [ ] o.e.j.s.Server Started @2885931ms
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=34397}
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=35433}
[junit4] 2> 2885833 ERROR (jetty-launcher-11747-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2885833 ERROR (jetty-launcher-11747-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 2885833 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-17T10:20:17.990054Z
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 2885834 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-17T10:20:17.990092Z
[junit4] 2> 2885835 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2885835 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2885836 INFO (zkConnectionManagerCallback-11749-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2885836 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2885836 INFO (zkConnectionManagerCallback-11751-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2885836 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2885836 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2885837 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2886628 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2886630 WARN (jetty-launcher-11747-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@56925e72[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2886630 WARN (jetty-launcher-11747-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@56925e72[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2886634 WARN (jetty-launcher-11747-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@1736b5ad[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2886634 WARN (jetty-launcher-11747-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@1736b5ad[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2886636 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45396/solr
[junit4] 2> 2886637 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2886638 INFO (zkConnectionManagerCallback-11759-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2886638 INFO (jetty-launcher-11747-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2886740 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2886741 INFO (zkConnectionManagerCallback-11761-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2886742 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2886841 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:35433_solr
[junit4] 2> 2886842 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.Overseer Overseer (id=72300755755466758-127.0.0.1:35433_solr-n_0000000000) starting
[junit4] 2> 2886847 INFO (OverseerStateUpdate-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:35433_solr
[junit4] 2> 2886848 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35433_solr
[junit4] 2> 2886849 INFO (OverseerStateUpdate-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2886851 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2886851 WARN (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_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> 2886873 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2886907 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35433.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2886919 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35433.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2886919 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_35433.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2886921 INFO (jetty-launcher-11747-thread-2) [n:127.0.0.1:35433_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node2/.
[junit4] 2> 2887054 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2887056 WARN (jetty-launcher-11747-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3321ada3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2887056 WARN (jetty-launcher-11747-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3321ada3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2887060 WARN (jetty-launcher-11747-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@331157b0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2887060 WARN (jetty-launcher-11747-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@331157b0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2887061 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:45396/solr
[junit4] 2> 2887062 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2887063 INFO (zkConnectionManagerCallback-11771-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887063 INFO (jetty-launcher-11747-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2887166 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2887167 INFO (zkConnectionManagerCallback-11773-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887167 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2887173 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2887177 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:34397_solr as DOWN
[junit4] 2> 2887178 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2887178 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34397_solr
[junit4] 2> 2887179 INFO (zkCallback-11760-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2887179 INFO (zkCallback-11772-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2887181 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2887181 WARN (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_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> 2887204 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2887235 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2887251 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2887251 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2887253 INFO (jetty-launcher-11747-thread-1) [n:127.0.0.1:34397_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/.
[junit4] 2> 2887290 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 2887291 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2887292 INFO (zkConnectionManagerCallback-11782-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887292 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2887294 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2887295 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45396/solr ready
[junit4] 2> 2887318 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 2887320 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2887321 INFO (zkConnectionManagerCallback-11787-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2887321 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2887322 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2887324 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:45396/solr ready
[junit4] 2> 2887376 INFO (qtp1621049547-32143) [n:127.0.0.1:35433_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2887381 INFO (qtp1621049547-32143) [n:127.0.0.1:35433_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> 2887393 INFO (qtp1621049547-32143) [n:127.0.0.1:35433_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:34397_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2887403 INFO (OverseerThreadFactory-8847-thread-2-processing-n:127.0.0.1:35433_solr) [n:127.0.0.1:35433_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 2887404 INFO (OverseerCollectionConfigSetProcessor-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_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> 2887509 WARN (OverseerThreadFactory-8847-thread-2-processing-n:127.0.0.1:35433_solr) [n:127.0.0.1:35433_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> 2887514 INFO (OverseerStateUpdate-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_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":"https://127.0.0.1:34397/solr",
[junit4] 2> "node_name":"127.0.0.1:34397_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887517 INFO (OverseerStateUpdate-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_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":"https://127.0.0.1:34397/solr",
[junit4] 2> "node_name":"127.0.0.1:34397_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2887769 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887771 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887780 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887780 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887798 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887798 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887801 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887801 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887805 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887805 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887806 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 2887806 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 2887808 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887808 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2887808 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 2887810 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] 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> 2887811 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887811 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2887811 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 2887921 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887921 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887922 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887922 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887924 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887924 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2887924 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887924 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2887925 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3ef80f87[.system_shard1_replica_n1] main]
[junit4] 2> 2887926 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@77b5362f[.system_shard1_replica_n2] main]
[junit4] 2> 2887928 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887928 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887928 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887928 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887928 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887928 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887929 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 2887929 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887930 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887930 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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 1658778885906497536
[junit4] 2> 2887931 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887934 INFO (searcherExecutor-8859-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_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@3ef80f87[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2887934 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887935 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 5 ms
[junit4] 2> 2887935 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887935 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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 1658778885911740416
[junit4] 2> 2887936 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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}, version=0}
[junit4] 2> 2887936 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2887938 INFO (searcherExecutor-8860-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:34397_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@77b5362f[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2887939 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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=0, core_node4=0}, version=1}
[junit4] 2> 2887939 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2887942 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2887942 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2887942 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:34397/solr/.system_shard1_replica_n1/
[junit4] 2> 2887942 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=https://127.0.0.1:34397/solr START replicas=[https://127.0.0.1:34397/solr/.system_shard1_replica_n2/] nUpdates=100
[junit4] 2> 2887943 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=https://127.0.0.1:34397/solr DONE. We have no versions. sync failed.
[junit4] 2> 2887955 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2887955 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2887955 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2887955 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/72300755755466760-core_node3-n_0000000000
[junit4] 2> 2887957 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:34397/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 2888059 INFO (zkCallback-11772-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> 2888059 INFO (zkCallback-11772-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> 2888059 INFO (zkCallback-11772-thread-3) [ ] 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> 2888060 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2888062 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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=293
[junit4] 2> 2888163 INFO (zkCallback-11772-thread-3) [ ] 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> 2888163 INFO (zkCallback-11772-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> 2888163 INFO (zkCallback-11772-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> 2888164 INFO (zkCallback-11772-thread-4) [ ] 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> 2888944 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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=1173
[junit4] 2> 2888946 INFO (qtp1621049547-32143) [n:127.0.0.1:35433_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> 2889045 INFO (zkCallback-11772-thread-3) [ ] 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> 2889045 INFO (zkCallback-11772-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> 2889045 INFO (zkCallback-11760-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> 2889045 INFO (zkCallback-11772-thread-4) [ ] 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> 2889045 INFO (zkCallback-11772-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> 2889047 INFO (qtp1621049547-32143) [n:127.0.0.1:35433_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:34397_solr&wt=javabin&version=2} status=0 QTime=1653
[junit4] 2> 2889047 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[A303F8636388D5B3]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 2889063 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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=1, core_node4=1}, version=2}
[junit4] 2> 2889118 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:34397/solr/.system_shard1_replica_n1/&wt=javabin&version=2}{add=[17052a9bf55T32cnwxmhm6y3i5t4slafbedem (1658778887092436992)]} 0 2
[junit4] 2> 2889119 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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={wt=javabin&version=2}{add=[17052a9bf55T32cnwxmhm6y3i5t4slafbedem (1658778887092436992)]} 0 58
[junit4] 2> 2889120 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658778887154302976,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2889121 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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@60bd2f40 commitCommandVersion:1658778887154302976
[junit4] 2> 2889122 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658778887156400128,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2889122 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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@2f08717e commitCommandVersion:1658778887156400128
[junit4] 2> 2889129 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@54af1009[.system_shard1_replica_n1] main]
[junit4] 2> 2889129 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2aca03bf[.system_shard1_replica_n2] main]
[junit4] 2> 2889129 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2889129 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2889132 INFO (searcherExecutor-8859-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_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@54af1009[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581934821279, java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2889132 INFO (searcherExecutor-8860-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:34397_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@2aca03bf[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581934821282, java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2889132 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:34397/solr/.system_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 10
[junit4] 2> 2889133 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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={_stateVer_=.system:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 12
[junit4] 2> 2889145 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889146 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889148 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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 params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889152 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 2889154 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889158 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889159 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 2889160 INFO (Thread-3922) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n2
[junit4] 2> 2889161 INFO (Thread-3922) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n1
[junit4] 2> 2889162 INFO (Thread-3922) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n1
[junit4] 2> 2889166 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889176 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889180 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889180 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 2889260 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_34397.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c7de1fe
[junit4] 2> 2889260 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 2889348 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889348 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2889352 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3175fee4[.system_shard1_replica_n1] main]
[junit4] 2> 2889355 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889355 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889355 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889356 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889356 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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> 2889359 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 2889363 INFO (searcherExecutor-8869-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_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@3175fee4[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581934821279, java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2889364 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@79927454[.system_shard1_replica_n1] main]
[junit4] 2> 2889364 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 2889369 INFO (searcherExecutor-8869-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_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@79927454[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, java.vendor=Oracle Corporation, os=Linux, timestamp=1581934821279, java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2889371 INFO (Thread-3922) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2889406 INFO (OverseerCollectionConfigSetProcessor-72300755755466758-127.0.0.1:35433_solr-n_0000000000) [n:127.0.0.1:35433_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2889407 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889408 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889408 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=19
[junit4] 2> 2889409 INFO (Thread-3922) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 2889413 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889413 INFO (Thread-3922) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 2889413 INFO (Thread-3922) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 2889414 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889414 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889414 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889415 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889416 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889416 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889416 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889417 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889417 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889418 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889418 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889418 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889419 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889419 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889419 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889420 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889420 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889421 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889421 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889421 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889422 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889422 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889422 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889423 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889423 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889424 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889424 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889424 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889425 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889425 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889425 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889426 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889426 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889427 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889427 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889427 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889428 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889428 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889428 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889429 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889430 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889430 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889430 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889430 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889431 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889432 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889432 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889432 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889433 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889433 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889433 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889434 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889434 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889435 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889435 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889435 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889436 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889436 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889436 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889437 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889437 INFO (qtp282917423-32144) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889438 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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> 2889438 INFO (qtp282917423-32144) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889438 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889439 INFO (qtp282917423-32140) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889439 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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> 2889439 INFO (qtp282917423-32140) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889440 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica https://127.0.0.1:34397/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 2889440 INFO (qtp282917423-32142) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 2889441 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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> 2889441 INFO (qtp282917423-32142) [n:127.0.0.1:34397_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/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2889441 ERROR (managedSchemaExecutor-8873-thread-1-processing-n:127.0.0.1:34397_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedInd
[...truncated too long message...]
eplica_n2/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: https://127.0.0.1:34397/solr/.system_shard1_replica_n2
[junit4] 2> 3025992 INFO (httpUriRequest-75160-thread-1-processing-x:.system_shard1_replica_n1 r:core_node3 n:127.0.0.1:34397_solr https:////127.0.0.1:34397//solr//.system_shard1_replica_n2 c:.system s:shard1) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.h.i.e.RetryExec I/O exception (java.net.SocketException) caught when processing request to {s}->https://127.0.0.1:34397: Socket closed
[junit4] 2> 3025992 INFO (httpUriRequest-75160-thread-1-processing-x:.system_shard1_replica_n1 r:core_node3 n:127.0.0.1:34397_solr https:////127.0.0.1:34397//solr//.system_shard1_replica_n2 c:.system s:shard1) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.h.i.e.RetryExec Retrying request to {s}->https://127.0.0.1:34397
[junit4] 2> 3026010 WARN (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Core core_node3 was interrupted waiting for schema version 2 to propagate to 1 replicas for collection .system
[junit4] 2> 3026010 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Took 136645.0ms for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 3026010 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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 params={wt=javabin&version=2} status=0 QTime=136860
[junit4] 2> 3026011 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@48c4fd92
[junit4] 2> 3026011 WARN (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Interrupted while trying to obtain lock to modify reporters registry: solr.core..system.shard1.replica_n1
[junit4] 2> 3026011 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection..system.shard1.leader, tag=SolrCore@48c4fd92
[junit4] 2> 3026027 INFO (qtp282917423-32214) [n:127.0.0.1:34397_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 3026027 INFO (qtp282917423-32214) [n:127.0.0.1:34397_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@162a0cc1 commitCommandVersion:0
[junit4] 2> 3026036 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 3026240 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 7 /solr/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> 25 /solr/collections/.system/state.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 27 /solr/overseer/queue
[junit4] 2> 18 /solr/collections
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 10 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 3026241 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:45396
[junit4] 2> 3026242 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:45396
[junit4] 2> 3026242 INFO (SUITE-SystemCollectionCompatTest-seed#[A303F8636388D5B3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 45396
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_A303F8636388D5B3-001
[junit4] 2> Feb 17, 2020 10:22:38 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), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5bc26219), locale=ru-KG, timezone=Asia/Srednekolymsk
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=393666608,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [DataDrivenBlockJoinTest, RulesTest, SuggesterTest, TestGroupingSearch, TestSlowCompositeReaderWrapper, TestInfoStreamLogging, InfixSuggestersTest, TestUpdate, CursorMarkTest, TestSortByMinMaxFunction, MultiThreadedOCPTest, TestCollectionsAPIViaSolrCloudCluster, SimpleMLTQParserTest, JWTAuthPluginIntegrationTest, TestSolrQueryParser, TestDynamicFieldNamesIndexCorrectly, TestCoreContainer, TestStressLiveNodes, DocValuesNotIndexedTest, DocValuesMissingTest, TestDistributedMissingSort, SolrXmlInZkTest, TestNamedUpdateProcessors, SchemaVersionSpecificBehaviorTest, TestDocTermOrds, TestCaffeineCache, TestConfigSetImmutable, ZkStateWriterTest, FullSolrCloudDistribCmdsTest, Tagger2Test, TestEmbeddedSolrServerSchemaAPI, TestSystemIdResolver, BooleanFieldTest, SolrCoreMetricManagerTest, TestCSVResponseWriter, TestLuceneIndexBackCompat, SearchHandlerTest, GraphQueryTest, TestManagedSchemaAPI, TestCodecSupport, TestSolrCoreProperties, SimplePostToolTest, DistributedExpandComponentTest, DateMathParserTest, TestAtomicUpdateErrorCases, SampleTest, RankQueryTest, TimeZoneUtilsTest, AutoscalingHistoryHandlerTest, TestChildDocTransformerHierarchy, SolrMetricsIntegrationTest, FieldAnalysisRequestHandlerTest, TestSimDistribStateManager, TestNonDefinedSimilarityFactory, NumericFieldsTest, TestRestoreCore, TestSubQueryTransformerCrossCore, TestPayloadCheckQParserPlugin, TestImpersonationWithHadoopAuth, TestLegacyNumericUtils, JavaBinAtomicUpdateMultivalueTest, TestSolrXml, TestTolerantUpdateProcessorCloud, TestUseDocValuesAsStored, RequiredFieldsTest, TolerantUpdateProcessorTest, MoveReplicaHDFSTest, SolrLogAuditLoggerPluginTest, TestCollationFieldDocValues, TestDistributedStatsComponentCardinality, TestRandomDVFaceting, NoCacheHeaderTest, TestConfigSetsAPIZkFailure, RootFieldTest, WordBreakSolrSpellCheckerTest, TestSweetSpotSimilarityFactory, TestSimScenario, TestStressUserVersions, TestSkipOverseerOperations, DeleteStatusTest, TestConfigsApi, HdfsRecoverLeaseTest, TestPivotHelperCode, XmlUpdateRequestHandlerTest, TestFacetMethods, TestCopyFieldCollectionResource, SolrPluginUtilsTest, TestNumericTerms32, HttpPartitionTest, TermVectorComponentDistributedTest, DistribJoinFromCollectionTest, NodeMarkersRegistrationTest, OverseerSolrResponseUnsafeSerializationTest, BufferStoreTest, TestCloudJSONFacetSKG, AutoAddReplicasPlanActionTest, TlogReplayBufferedWhileIndexingTest, RemoteQueryErrorTest, XmlInterpolationTest, AtomicUpdateProcessorFactoryTest, TestDistribDocBasedVersion, TestSystemCollAutoCreate, CustomCollectionTest, TestUniqueKeyFieldResource, TestJsonFacetsStatsParsing, TestRuleBasedAuthorizationPlugin, TestComplexPhraseQParserPlugin, PingRequestHandlerTest, TestQueryTypes, ExitableDirectoryReaderTest, SearchRateTriggerTest, TestReplicaProperties, DistributedFacetPivotWhiteBoxTest, CustomTermsComponentTest, UniqFieldsUpdateProcessorFactoryTest, TestSolrDeletionPolicy1, TestLockTree, TestCharFilters, TestRealTimeGet, ClassificationUpdateProcessorTest, TestPushWriter, ChaosMonkeySafeLeaderTest, TestFoldingMultitermQuery, CleanupOldIndexTest, CacheHeaderTest, TestFreeTextSuggestions, ClusterStateTest, IndexSizeTriggerMixedBoundsTest, RangeFacetCloudTest, BJQFilterAccessibleTest, TestSegmentSorting, TestReload, TestClusterStateMutator, CollectionsAPIDistributedZkTest, TestLogWatcher, TestFunctionQuery, MetricsHandlerTest, CollectionStateFormat2Test, TestReplicationHandlerBackup, TestSolrCoreParser, TestFieldCacheVsDocValues, ConfigureRecoveryStrategyTest, TestFieldTypeResource, TestDFISimilarityFactory, TestFieldSortValues, TestFieldCacheReopen, SpellPossibilityIteratorTest, EchoParamsTest, MinimalSchemaTest, OutputWriterTest, TestCrossCoreJoin, TestCursorMarkWithoutUniqueKey, TestDistributedSearch, TestSimpleTrackingShardHandler, ActionThrottleTest, AssignBackwardCompatibilityTest, ConcurrentCreateRoutedAliasTest, ConfigSetsAPITest, CreateRoutedAliasTest, DeleteInactiveReplicaTest, DeleteLastCustomShardedReplicaTest, DeleteNodeTest, DistribCursorPagingTest, DistribDocExpirationUpdateProcessorTest, LeaderFailureAfterFreshStartTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerModifyCollectionTest, OverseerTaskQueueTest, RecoveryAfterSoftCommitTest, ReplicationFactorTest, SliceStateTest, SolrCLIZkUtilsTest, SystemCollectionCompatTest]
[junit4] Completed [526/904 (1!)] on J0 in 140.80s, 1 test, 1 error <<< FAILURES!
[...truncated 53840 lines...]
[JENKINS] Lucene-Solr-Tests-master - Build # 4267 - Still Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/4267/
1 tests failed.
FAILED: org.apache.solr.cloud.TestTlogReplica.testRemoveLeader
Error Message:
Unexpected number of tlog replicas: DocCollection(tlog_replica_test_remove_leader//collections/tlog_replica_test_remove_leader/state.json/7)={ "pullReplicas":"0", "replicationFactor":"0", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{"core_node4":{ "core":"tlog_replica_test_remove_leader_shard1_replica_t2", "base_url":"https://127.0.0.1:33847/solr", "node_name":"127.0.0.1:33847_solr", "state":"recovering", "type":"TLOG", "force_set_state":"false"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"100", "autoAddReplicas":"false", "nrtReplicas":"0", "tlogReplicas":"2"} expected:<1> but was:<0>
Stack Trace:
java.lang.AssertionError: Unexpected number of tlog replicas: DocCollection(tlog_replica_test_remove_leader//collections/tlog_replica_test_remove_leader/state.json/7)={
"pullReplicas":"0",
"replicationFactor":"0",
"shards":{"shard1":{
"range":"80000000-7fffffff",
"state":"active",
"replicas":{"core_node4":{
"core":"tlog_replica_test_remove_leader_shard1_replica_t2",
"base_url":"https://127.0.0.1:33847/solr",
"node_name":"127.0.0.1:33847_solr",
"state":"recovering",
"type":"TLOG",
"force_set_state":"false"}}}},
"router":{"name":"compositeId"},
"maxShardsPerNode":"100",
"autoAddReplicas":"false",
"nrtReplicas":"0",
"tlogReplicas":"2"} expected:<1> but was:<0>
at __randomizedtesting.SeedInfo.seed([B06CE2E066E32C9C:292C2584216A4CD6]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.apache.solr.cloud.TestTlogReplica.assertNumberOfReplicas(TestTlogReplica.java:827)
at org.apache.solr.cloud.TestTlogReplica.doReplaceLeader(TestTlogReplica.java:403)
at org.apache.solr.cloud.TestTlogReplica.testRemoveLeader(TestTlogReplica.java:319)
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$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:834)
Build Log:
[...truncated 14152 lines...]
[junit4] Suite: org.apache.solr.cloud.TestTlogReplica
[junit4] 2> 2289271 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/server/solr/configsets/_default/conf'
[junit4] 2> 2289271 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2289271 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/data-dir-118-001
[junit4] 2> 2289271 WARN (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 2289271 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2289272 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) 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> 2289273 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001
[junit4] 2> 2289273 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2289274 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2289274 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2289374 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:44529
[junit4] 2> 2289374 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:44529
[junit4] 2> 2289374 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44529
[junit4] 2> 2289374 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44529
[junit4] 2> 2289376 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289379 INFO (zkConnectionManagerCallback-7122-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289379 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2289382 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289383 INFO (zkConnectionManagerCallback-7124-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289383 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2289384 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289385 INFO (zkConnectionManagerCallback-7126-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289385 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2289495 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 2289495 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.s.h.g.GzipHandler minGzipSize of 0 is inefficient for short content, break even is size 23
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2289495 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2289499 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2289499 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2289499 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2289501 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@21271d60{/solr,null,AVAILABLE}
[junit4] 2> 2289501 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2289501 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2289501 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2289502 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@ea847d4{/solr,null,AVAILABLE}
[junit4] 2> 2289502 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@50796292{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:33847}
[junit4] 2> 2289502 INFO (jetty-launcher-7127-thread-2) [ ] o.e.j.s.Server Started @2289639ms
[junit4] 2> 2289502 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=33847}
[junit4] 2> 2289503 ERROR (jetty-launcher-7127-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-17T12:26:05.196260Z
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2dc8f94e{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:41306}
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.e.j.s.Server Started @2289640ms
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41306}
[junit4] 2> 2289503 ERROR (jetty-launcher-7127-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr
[junit4] 2> 2289503 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-17T12:26:05.196836Z
[junit4] 2> 2289504 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289504 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289505 INFO (zkConnectionManagerCallback-7129-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289505 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2289505 INFO (zkConnectionManagerCallback-7131-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289505 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2289506 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2289506 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2289973 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2289974 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@72b650d3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2289974 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@72b650d3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2289978 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5a1ec797[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2289978 WARN (jetty-launcher-7127-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5a1ec797[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2289980 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44529/solr
[junit4] 2> 2289980 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2289983 INFO (zkConnectionManagerCallback-7139-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2289984 INFO (jetty-launcher-7127-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2290022 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2290024 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3ecfce68[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2290024 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3ecfce68[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2290027 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3ed1f629[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2290027 WARN (jetty-launcher-7127-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3ed1f629[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2290029 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:44529/solr
[junit4] 2> 2290030 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2290031 INFO (zkConnectionManagerCallback-7145-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2290031 INFO (jetty-launcher-7127-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2290087 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2290088 INFO (zkConnectionManagerCallback-7147-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2290088 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2290187 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2290189 INFO (zkConnectionManagerCallback-7151-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2290189 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2290199 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:33847_solr
[junit4] 2> 2290200 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.Overseer Overseer (id=72301250368569351-127.0.0.1:33847_solr-n_0000000000) starting
[junit4] 2> 2290201 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41306_solr
[junit4] 2> 2290202 INFO (zkCallback-7150-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2290202 INFO (zkCallback-7146-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2290205 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2290205 WARN (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_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> 2290207 INFO (OverseerStateUpdate-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:33847_solr
[junit4] 2> 2290207 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:33847_solr as DOWN
[junit4] 2> 2290208 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2290208 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33847_solr
[junit4] 2> 2290210 INFO (zkCallback-7150-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2290210 INFO (zkCallback-7146-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2290212 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2290213 WARN (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_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> 2290226 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2290233 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2290263 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33847.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290263 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41306.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290279 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33847.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290279 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33847.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290280 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41306.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290280 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41306.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290281 INFO (jetty-launcher-7127-thread-2) [n:127.0.0.1:33847_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node2/.
[junit4] 2> 2290282 INFO (jetty-launcher-7127-thread-1) [n:127.0.0.1:41306_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node1/.
[junit4] 2> 2290353 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 2290354 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2290355 INFO (zkConnectionManagerCallback-7162-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2290356 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2290357 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2290359 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:44529/solr ready
[junit4] 2> 2290362 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.TestTlogReplica Using legacyCloud?: false
[junit4] 2> 2290397 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :clusterprop with params val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2290399 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={val=false&name=legacyCloud&action=CLUSTERPROP&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 2290425 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAddDocs
[junit4] 2> 2290428 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_add_docs&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2290431 INFO (OverseerThreadFactory-7810-thread-1-processing-n:127.0.0.1:33847_solr) [n:127.0.0.1:33847_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection tlog_replica_test_add_docs
[junit4] 2> 2290542 INFO (OverseerStateUpdate-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_add_docs",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_add_docs_shard1_replica_t1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:33847/solr",
[junit4] 2> "node_name":"127.0.0.1:33847_solr",
[junit4] 2> "type":"TLOG",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2290756 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 2290766 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2290775 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.IndexSchema [tlog_replica_test_add_docs_shard1_replica_t1] Schema name=minimal
[junit4] 2> 2290778 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2290778 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_add_docs_shard1_replica_t1' using configuration from configset conf, trusted=true
[junit4] 2> 2290778 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33847.solr.core.tlog_replica_test_add_docs.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_add_docs.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2290778 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [[tlog_replica_test_add_docs_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node2/tlog_replica_test_add_docs_shard1_replica_t1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node2/./tlog_replica_test_add_docs_shard1_replica_t1/data/]
[junit4] 2> 2290859 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2290859 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2290861 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2290861 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2290863 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2420006b[tlog_replica_test_add_docs_shard1_replica_t1] main]
[junit4] 2> 2290864 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2290865 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2290865 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2290865 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1658786798955921408
[junit4] 2> 2290869 INFO (searcherExecutor-7819-thread-1-processing-n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 c:tlog_replica_test_add_docs s:shard1 r:core_node2) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] Registered new searcher Searcher@2420006b[tlog_replica_test_add_docs_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2290872 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 2290872 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_add_docs/leaders/shard1
[junit4] 2> 2290875 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2290875 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2290875 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33847/solr/tlog_replica_test_add_docs_shard1_replica_t1/
[junit4] 2> 2290876 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2290876 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SyncStrategy https://127.0.0.1:33847/solr/tlog_replica_test_add_docs_shard1_replica_t1/ has no replicas
[junit4] 2> 2290876 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t1 stopping background replication from leader
[junit4] 2> 2290876 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/tlog_replica_test_add_docs/leaders/shard1/leader after winning as /collections/tlog_replica_test_add_docs/leader_elect/shard1/election/72301250368569351-core_node2-n_0000000000
[junit4] 2> 2290878 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33847/solr/tlog_replica_test_add_docs_shard1_replica_t1/ shard1
[junit4] 2> 2290980 INFO (zkCallback-7146-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2290981 INFO (zkCallback-7146-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2290981 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2290983 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=tlog_replica_test_add_docs_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_add_docs&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=227
[junit4] 2> 2290987 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_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> 2291084 INFO (zkCallback-7146-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291084 INFO (zkCallback-7146-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291084 INFO (zkCallback-7146-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291084 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_add_docs&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=1&wt=javabin&version=2} status=0 QTime=657
[junit4] 2> 2291085 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase waitForState (tlog_replica_test_add_docs): Expected collection to be created with 1 shards and 1 replicas
[junit4] 2> 2291086 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 2291086 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 2291086 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 1 expected replica count: 1
[junit4] 2> 2291093 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={core_node2=1}, version=1}
[junit4] 2> 2291093 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1658786799192899584)]} 0 3
[junit4] 2> 2291095 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658786799197093888,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2291095 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1fad3812 commitCommandVersion:1658786799197093888
[junit4] 2> 2291098 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@453e0001[tlog_replica_test_add_docs_shard1_replica_t1] main]
[junit4] 2> 2291098 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2291101 INFO (searcherExecutor-7819-thread-1-processing-n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 c:tlog_replica_test_add_docs s:shard1 r:core_node2) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] Registered new searcher Searcher@453e0001[tlog_replica_test_add_docs_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1581942366790, java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64}])))}
[junit4] 2> 2291101 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_add_docs_shard1_replica_t1] webapp=/solr path=/update params={_stateVer_=tlog_replica_test_add_docs:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
[junit4] 2> 2291114 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 2291145 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=1 status=0 QTime=0
[junit4] 2> 2291160 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_add_docs s:shard1 r:core_node2 x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_add_docs_shard1_replica_t1] webapp=/solr path=/admin/plugins params={qt=/admin/plugins&stats=true&wt=javabin&version=2} status=0 QTime=14
[junit4] 2> 2291167 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.TestTlogReplica tearDown deleting collection
[junit4] 2> 2291167 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :delete with params name=tlog_replica_test_add_docs&action=DELETE&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2291171 INFO (OverseerCollectionConfigSetProcessor-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_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> 2291171 INFO (OverseerThreadFactory-7810-thread-2-processing-n:127.0.0.1:33847_solr) [n:127.0.0.1:33847_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=UNLOAD&deleteInstanceDir=true&deleteDataDir=true&deleteMetricsHistory=true, asyncId=null
[junit4] 2> 2291172 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.tlog_replica_test_add_docs.shard1.replica_t1, tag=null
[junit4] 2> 2291172 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@26ba9bb8: rootName = solr_33847, domain = solr.core.tlog_replica_test_add_docs.shard1.replica_t1, service url = null, agent id = null] for registry solr.core.tlog_replica_test_add_docs.shard1.replica_t1 / com.codahale.metrics.MetricRegistry@68fbd674
[junit4] 2> 2291201 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkController tlog_replica_test_add_docs_shard1_replica_t1 stopping background replication from leader
[junit4] 2> 2291201 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.SolrCore [tlog_replica_test_add_docs_shard1_replica_t1] CLOSING SolrCore org.apache.solr.core.SolrCore@276b6598
[junit4] 2> 2291201 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.tlog_replica_test_add_docs.shard1.replica_t1, tag=SolrCore@276b6598
[junit4] 2> 2291201 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.tlog_replica_test_add_docs.shard1.leader, tag=SolrCore@276b6598
[junit4] 2> 2291202 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 2291206 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_add_docs/terms/shard1 to Terms{values={}, version=2}
[junit4] 2> 2291207 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_add_docs_shard1_replica_t1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={deleteInstanceDir=true&deleteMetricsHistory=true&core=tlog_replica_test_add_docs_shard1_replica_t1&qt=/admin/cores&deleteDataDir=true&action=UNLOAD&wt=javabin&version=2} status=0 QTime=35
[junit4] 2> 2291310 INFO (zkCallback-7146-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291310 INFO (zkCallback-7146-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291311 INFO (zkCallback-7146-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDeleted path:/collections/tlog_replica_test_add_docs/state.json] for collection [tlog_replica_test_add_docs] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2291319 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=tlog_replica_test_add_docs&action=DELETE&wt=javabin&version=2} status=0 QTime=151
[junit4] 2> 2291319 INFO (TEST-TestTlogReplica.testAddDocs-seed#[B06CE2E066E32C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testAddDocs
[junit4] 2> 2291340 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBasicLeaderElection
[junit4] 2> 2291340 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_basic_leader_election&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2291343 INFO (OverseerThreadFactory-7810-thread-3-processing-n:127.0.0.1:33847_solr) [n:127.0.0.1:33847_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection tlog_replica_test_basic_leader_election
[junit4] 2> 2291343 INFO (OverseerCollectionConfigSetProcessor-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 2291553 INFO (OverseerStateUpdate-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_basic_leader_election",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_basic_leader_election_shard1_replica_t1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:41306/solr",
[junit4] 2> "node_name":"127.0.0.1:41306_solr",
[junit4] 2> "type":"TLOG",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2291556 INFO (OverseerStateUpdate-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"tlog_replica_test_basic_leader_election",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"tlog_replica_test_basic_leader_election_shard1_replica_t2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:33847/solr",
[junit4] 2> "node_name":"127.0.0.1:33847_solr",
[junit4] 2> "type":"TLOG",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2291760 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=tlog_replica_test_basic_leader_election_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_basic_leader_election&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 2291769 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2291788 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.s.IndexSchema [tlog_replica_test_basic_leader_election_shard1_replica_t2] Schema name=minimal
[junit4] 2> 2291790 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2291790 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_basic_leader_election_shard1_replica_t2' using configuration from configset conf, trusted=true
[junit4] 2> 2291791 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_33847.solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t2' (registry 'solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2291791 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SolrCore [[tlog_replica_test_basic_leader_election_shard1_replica_t2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node2/tlog_replica_test_basic_leader_election_shard1_replica_t2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node2/./tlog_replica_test_basic_leader_election_shard1_replica_t2/data/]
[junit4] 2> 2291797 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_basic_leader_election_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_basic_leader_election&shard=shard1&wt=javabin&version=2&replicaType=TLOG
[junit4] 2> 2291798 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2291808 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2291817 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.s.IndexSchema [tlog_replica_test_basic_leader_election_shard1_replica_t1] Schema name=minimal
[junit4] 2> 2291820 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2291820 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.CoreContainer Creating SolrCore 'tlog_replica_test_basic_leader_election_shard1_replica_t1' using configuration from configset conf, trusted=true
[junit4] 2> 2291820 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41306.solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t1' (registry 'solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1a5af885
[junit4] 2> 2291820 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.SolrCore [[tlog_replica_test_basic_leader_election_shard1_replica_t1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node1/tlog_replica_test_basic_leader_election_shard1_replica_t1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001/tempDir-001/node1/./tlog_replica_test_basic_leader_election_shard1_replica_t1/data/]
[junit4] 2> 2291876 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2291876 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2291879 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2291879 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2291880 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@62d284bf[tlog_replica_test_basic_leader_election_shard1_replica_t2] main]
[junit4] 2> 2291883 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2291883 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2291884 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2291884 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1658786800024420352
[junit4] 2> 2291888 INFO (searcherExecutor-7824-thread-1-processing-n:127.0.0.1:33847_solr x:tlog_replica_test_basic_leader_election_shard1_replica_t2 c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SolrCore [tlog_replica_test_basic_leader_election_shard1_replica_t2] Registered new searcher Searcher@62d284bf[tlog_replica_test_basic_leader_election_shard1_replica_t2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2291892 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_basic_leader_election/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 2291892 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_basic_leader_election/leaders/shard1
[junit4] 2> 2291899 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9998ms
[junit4] 2> 2291905 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2291905 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2291908 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2291908 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2291909 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@623f18c0[tlog_replica_test_basic_leader_election_shard1_replica_t1] main]
[junit4] 2> 2291911 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2291912 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2291912 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2291912 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1658786800053780480
[junit4] 2> 2291916 INFO (searcherExecutor-7825-thread-1-processing-n:127.0.0.1:41306_solr x:tlog_replica_test_basic_leader_election_shard1_replica_t1 c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.SolrCore [tlog_replica_test_basic_leader_election_shard1_replica_t1] Registered new searcher Searcher@623f18c0[tlog_replica_test_basic_leader_election_shard1_replica_t1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2291919 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_basic_leader_election/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 2291919 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/tlog_replica_test_basic_leader_election/leaders/shard1
[junit4] 2> 2292401 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2292401 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2292401 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:33847/solr/tlog_replica_test_basic_leader_election_shard1_replica_t2/
[junit4] 2> 2292402 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_basic_leader_election_shard1_replica_t2 url=https://127.0.0.1:33847/solr START replicas=[https://127.0.0.1:41306/solr/tlog_replica_test_basic_leader_election_shard1_replica_t1/] nUpdates=100
[junit4] 2> 2292402 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.PeerSync PeerSync: core=tlog_replica_test_basic_leader_election_shard1_replica_t2 url=https://127.0.0.1:33847/solr DONE. We have no versions. sync failed.
[junit4] 2> 2292414 INFO (qtp657494590-22589) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.S.Request [tlog_replica_test_basic_leader_election_shard1_replica_t1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2292415 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2292415 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] 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> 2292415 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ZkController tlog_replica_test_basic_leader_election_shard1_replica_t2 stopping background replication from leader
[junit4] 2> 2292415 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/tlog_replica_test_basic_leader_election/leaders/shard1/leader after winning as /collections/tlog_replica_test_basic_leader_election/leader_elect/shard1/election/72301250368569351-core_node4-n_0000000000
[junit4] 2> 2292417 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:33847/solr/tlog_replica_test_basic_leader_election_shard1_replica_t2/ shard1
[junit4] 2> 2292519 INFO (zkCallback-7146-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2292521 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2292523 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=tlog_replica_test_basic_leader_election_shard1_replica_t2&action=CREATE&numShards=1&collection=tlog_replica_test_basic_leader_election&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=763
[junit4] 2> 2292624 INFO (zkCallback-7146-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2292624 INFO (zkCallback-7146-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2292923 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.ZkController tlog_replica_test_basic_leader_election_shard1_replica_t1 starting background replication from leader
[junit4] 2> 2292924 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.ReplicateFromLeader Will start replication from leader with poll interval: 00:00:01
[junit4] 2> 2292926 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms
[junit4] 2> 2292926 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2292928 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=tlog_replica_test_basic_leader_election_shard1_replica_t1&action=CREATE&numShards=1&collection=tlog_replica_test_basic_leader_election&shard=shard1&wt=javabin&version=2&replicaType=TLOG} status=0 QTime=1131
[junit4] 2> 2292930 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_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> 2293029 INFO (zkCallback-7146-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2293029 INFO (zkCallback-7146-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2293029 INFO (zkCallback-7150-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2293029 INFO (zkCallback-7150-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2293029 INFO (qtp1518406114-22588) [n:127.0.0.1:33847_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={pullReplicas=0&collection.configName=conf&maxShardsPerNode=100&name=tlog_replica_test_basic_leader_election&nrtReplicas=0&action=CREATE&numShards=1&tlogReplicas=2&wt=javabin&version=2} status=0 QTime=1689
[junit4] 2> 2293030 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase waitForState (tlog_replica_test_basic_leader_election): Expected collection to be created with 1 shards and 2 replicas
[junit4] 2> 2293031 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 2293031 INFO (watches-7159-thread-1) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 2293031 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 2293031 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 2 expected replica count: 2
[junit4] 2> 2293072 INFO (qtp657494590-22585) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_basic_leader_election_shard1_replica_t1] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1658786801230282752&distrib.from=https://127.0.0.1:33847/solr/tlog_replica_test_basic_leader_election_shard1_replica_t2/&wt=javabin&version=2}{deleteByQuery=*:* (-1658786801230282752)} 0 1
[junit4] 2> 2293073 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1658786801271177216,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2293073 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2293073 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2293075 INFO (qtp657494590-22587) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_basic_leader_election_shard1_replica_t1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=https://127.0.0.1:33847/solr/tlog_replica_test_basic_leader_election_shard1_replica_t2/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 0
[junit4] 2> 2293076 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/tlog_replica_test_basic_leader_election/terms/shard1 to Terms{values={core_node3=1, core_node4=1}, version=2}
[junit4] 2> 2293076 INFO (qtp1518406114-22586) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_basic_leader_election_shard1_replica_t2] webapp=/solr path=/update params={_stateVer_=tlog_replica_test_basic_leader_election:5&commit=true&wt=javabin&version=2}{deleteByQuery=*:* (-1658786801230282752), commit=} 0 42
[junit4] 2> 2293079 INFO (qtp657494590-22589) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_basic_leader_election_shard1_replica_t1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:33847/solr/tlog_replica_test_basic_leader_election_shard1_replica_t2/&wt=javabin&version=2}{add=[1 (1658786801275371520), 2 (1658786801276420096)]} 0 0
[junit4] 2> 2293080 INFO (qtp1518406114-22584) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.p.LogUpdateProcessorFactory [tlog_replica_test_basic_leader_election_shard1_replica_t2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1658786801275371520), 2 (1658786801276420096)]} 0 2
[junit4] 2> 2293080 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=560345014
[junit4] 2> 2293081 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:33847_solr
[junit4] 2> 2293081 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2293081 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:33847_solr as DOWN
[junit4] 2> 2293083 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.c.SolrCore [tlog_replica_test_basic_leader_election_shard1_replica_t2] CLOSING SolrCore org.apache.solr.core.SolrCore@78d9af3a
[junit4] 2> 2293083 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t2, tag=SolrCore@78d9af3a
[junit4] 2> 2293083 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2ed882c1: rootName = solr_33847, domain = solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t2, service url = null, agent id = null] for registry solr.core.tlog_replica_test_basic_leader_election.shard1.replica_t2 / com.codahale.metrics.MetricRegistry@3c02b6ab
[junit4] 2> 2293100 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.tlog_replica_test_basic_leader_election.shard1.leader, tag=SolrCore@78d9af3a
[junit4] 2> 2293101 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 2293101 INFO (coreCloseExecutor-7836-thread-1) [n:127.0.0.1:33847_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node4 x:tlog_replica_test_basic_leader_election_shard1_replica_t2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@5740fe09 commitCommandVersion:0
[junit4] 2> 2293105 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2293105 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@41c1dafc: rootName = solr_33847, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@304f5112
[junit4] 2> 2293115 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2293115 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@4c7ba28f: rootName = solr_33847, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7160e3a2
[junit4] 2> 2293121 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2293121 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@65e27576: rootName = solr_33847, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@3b5a946
[junit4] 2> 2293121 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2293123 INFO (closeThreadPool-7169-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72301250368569351-127.0.0.1:33847_solr-n_0000000000) closing
[junit4] 2> 2293123 INFO (OverseerStateUpdate-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [n:127.0.0.1:33847_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:33847_solr
[junit4] 2> 2293123 INFO (OverseerAutoScalingTriggerThread-72301250368569351-127.0.0.1:33847_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2293130 INFO (zkCallback-7161-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2293130 INFO (closeThreadPool-7169-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72301250368569351-127.0.0.1:33847_solr-n_0000000000) closing
[junit4] 2> 2293130 INFO (zkCallback-7150-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2293131 INFO (zkCallback-7150-thread-3) [ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41306_solr
[junit4] 2> 2293132 INFO (zkCallback-7150-thread-3) [n:127.0.0.1:41306_solr ] o.a.s.c.Overseer Overseer (id=72301250368569352-127.0.0.1:41306_solr-n_0000000001) starting
[junit4] 2> 2293132 INFO (zkCallback-7150-thread-2) [n:127.0.0.1:41306_solr c:tlog_replica_test_basic_leader_election s:shard1 r:core_node3 x:tlog_replica_test_basic_leader_election_shard1_replica_t1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2293136 INFO (OverseerStateUpdate-72301250368569352-127.0.0.1:41306_solr-n_0000000001) [n:127.0.0.1:41306_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41306_solr
[junit4] 2> 2293140 INFO (zkCallback-7150-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [1])
[junit4] 2> 2293140 INFO (zkCallback-7150-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [1])
[junit4] 2> 2293230 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.Overseer Overseer (id=72301250368569351-127.0.0.1:33847_solr-n_0000000000) closing
[junit4] 2> 2293232 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@50796292{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:0}
[junit4] 2> 2293232 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@21271d60{/solr,null,UNAVAILABLE}
[junit4] 2> 2293232 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2293234 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase waitForState (tlog_replica_test_basic_leader_election): Replica not removed
[junit4] 2> 2293236 INFO (TEST-TestTlogReplica.testBasicLeaderElection-seed#[B06CE2E066E32C9C]) [ ] o.a.s.c.SolrCloudTestCase waitForState (tlog_replica_test_basic_leader_election): Expect new leader
[junit4] 2> 2293242 INFO (zkCallback-7150-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/tlog_replica_test_basic_leader_election/state.json] for collection [tlog_replica_test_basic_leader_election] has occurred - updating... (live nodes size: [1])
[junit4] 2> 2293242 INFO
[...truncated too long message...]
O (jetty-closer-7345-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72301250368569368-127.0.0.1:33847_solr-n_0000000006) closing
[junit4] 2> 2373584 INFO (jetty-closer-7345-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7ec6977f{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:33847}
[junit4] 2> 2373584 INFO (jetty-closer-7345-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@11970021{/solr,null,UNAVAILABLE}
[junit4] 2> 2373584 INFO (jetty-closer-7345-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2373585 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 2373804 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> 30 /solr/collections/tlog_replica_test_create_delete/terms/shard2
[junit4] 2> 30 /solr/collections/tlog_replica_test_create_delete/terms/shard1
[junit4] 2> 28 /solr/configs/conf
[junit4] 2> 18 /solr/collections/tlog_replica_test_recovery/terms/shard1
[junit4] 2> 16 /solr/collections/tlog_replica_test_basic_leader_election/terms/shard1
[junit4] 2> 16 /solr/collections/tlog_replica_test_kill_leader/terms/shard1
[junit4] 2> 12 /solr/collections/tlog_replica_test_remove_leader/terms/shard1
[junit4] 2> 10 /solr/collections/tlog_replica_test_delete_by_id/terms/shard1
[junit4] 2> 9 /solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/terms/shard1
[junit4] 2> 9 /solr/aliases.json
[junit4] 2> 9 /solr/collections/tlog_replica_test_only_leader_indexes/terms/shard1
[junit4] 2> 8 /solr/packages.json
[junit4] 2> 8 /solr/security.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/state.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_kill_leader/state.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_recovery/state.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_create_delete/state.json
[junit4] 2> 6 /solr/collections/tlog_replica_test_basic_leader_election/state.json
[junit4] 2> 5 /solr/collections/tlog_replica_test_recovery/collectionprops.json
[junit4] 2> 5 /solr/collections/tlog_replica_test_add_remove_tlog_replica/terms/shard2
[junit4] 2> 4 /solr/collections/tlog_replica_test_add_docs/terms/shard1
[junit4] 2> 4 /solr/collections/tlog_replica_test_add_remove_tlog_replica/terms/shard1
[junit4] 2> 4 /solr/collections/tlog_replica_test_delete_by_id/state.json
[junit4] 2> 3 /solr/collections/tlog_replica_test_add_docs/state.json
[junit4] 2> 3 /solr/collections/tlog_replica_test_basic_leader_election/collectionprops.json
[junit4] 2> 3 /solr/collections/tlog_replica_test_real_time_get/terms/shard1
[junit4] 2> 3 /solr/collections/tlog_replica_test_kill_leader/collectionprops.json
[junit4] 2> 3 /solr/collections/tlog_replica_test_real_time_get/state.json
[junit4] 2> 3 /solr/collections/tlog_replica_test_only_leader_indexes/state.json
[junit4] 2> 2 /solr/collections/tlog_replica_test_delete_by_id/collectionprops.json
[junit4] 2> 2 /solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/collectionprops.json
[junit4] 2> 2 /solr/collections/tlog_replica_test_remove_leader/state.json
[junit4] 2> 2 /solr/collections/tlog_replica_test_add_remove_tlog_replica/collectionprops.json
[junit4] 2> 2 /solr/collections/tlog_replica_test_only_leader_indexes/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 97 /solr/collections/tlog_replica_test_recovery/state.json
[junit4] 2> 78 /solr/collections/tlog_replica_test_add_remove_tlog_replica/state.json
[junit4] 2> 69 /solr/collections/tlog_replica_test_create_delete/state.json
[junit4] 2> 49 /solr/collections/tlog_replica_test_out_of_order_db_qwith_in_place_updates/state.json
[junit4] 2> 49 /solr/collections/tlog_replica_test_kill_leader/state.json
[junit4] 2> 49 /solr/collections/tlog_replica_test_basic_leader_election/state.json
[junit4] 2> 31 /solr/collections/tlog_replica_test_remove_leader/state.json
[junit4] 2> 25 /solr/collections/tlog_replica_test_only_leader_indexes/state.json
[junit4] 2> 16 /solr/collections/tlog_replica_test_delete_by_id/state.json
[junit4] 2> 12 /solr/clusterprops.json
[junit4] 2> 10 /solr/collections/tlog_replica_test_add_docs/state.json
[junit4] 2> 10 /solr/collections/tlog_replica_test_real_time_get/state.json
[junit4] 2> 9 /solr/clusterstate.json
[junit4] 2> 5 /solr/autoscaling.json
[junit4] 2> 4 /solr/collections/tlog_replica_test_recovery/leader_elect/shard1/election/72301250368569356-core_node4-n_0000000000
[junit4] 2> 3 /solr/overseer_elect/election/72301250368569356-127.0.0.1:33847_solr-n_0000000002
[junit4] 2> 2 /solr/collections/tlog_replica_test_create_delete/leader_elect/shard1/election/72301250368569368-core_node3-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 344 /solr/overseer/queue
[junit4] 2> 102 /solr/overseer/collection-queue-work
[junit4] 2> 81 /solr/collections
[junit4] 2> 44 /solr/live_nodes
[junit4] 2> 5 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 5 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 5 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 2373808 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:44529
[junit4] 2> 2373808 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:44529
[junit4] 2> 2373808 INFO (SUITE-TestTlogReplica-seed#[B06CE2E066E32C9C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 44529
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J2/temp/solr.cloud.TestTlogReplica_B06CE2E066E32C9C-001
[junit4] 2> Feb 17, 2020 12:27:29 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=SimpleText, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@fd2948a), locale=gu, timezone=Africa/Bamako
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=124165280,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestSimPolicyCloud, TestBulkSchemaAPI, LargeFieldTest, ResponseLogComponentTest, TestDistributedTracing, DeleteShardTest, OverseerCollectionConfigSetProcessorTest, IndexSizeTriggerTest, ProtectedTermFilterFactoryTest, TestDelegationWithHadoopAuth, DocExpirationUpdateProcessorFactoryTest, SolrCmdDistributorTest, PKIAuthenticationIntegrationTest, TestImplicitCoreProperties, TestHighFrequencyDictionaryFactory, TaggingAttributeTest, TestDownShardTolerantSearch, TestLegacyBM25SimilarityFactory, CurrencyRangeFacetCloudTest, TestFastOutputStream, TestStandardQParsers, SolrCloudReportersTest, BJQParserTest, SuggesterTSTTest, TestCorePropertiesReload, TestHttpShardHandlerFactory, TestConfigSets, TestSolrIndexConfig, LeaderVoteWaitTimeoutTest, AdminHandlersProxyTest, V2StandaloneTest, TestEmbeddedSolrServerConstructors, SpatialRPTFieldTypeTest, TestSSLRandomization, SharedFSAutoReplicaFailoverTest, TestReqParamsAPI, SolrIndexSplitterTest, TestSearchPerf, FacetPivotSmallTest, TestFieldCache, TestCustomSort, TestHdfsUpdateLog, CreateCollectionCleanupTest, TestConfigOverlay, CdcrBidirectionalTest, TestStressThreadBackup, TestDistributedGrouping, ZookeeperStatusHandlerTest, CoreMergeIndexesAdminHandlerTest, SolrLogPostToolTest, TestSQLHandlerNonCloud, SearchRateTriggerIntegrationTest, TestTextField, ParsingFieldUpdateProcessorsTest, HttpSolrCallGetCoreTest, ReindexCollectionTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestBulkSchemaConcurrent, ClassificationUpdateProcessorIntegrationTest, TestDocumentBuilder, DirectoryFactoryTest, NotRequiredUniqueKeyTest, TestMultiValuedNumericRangeQuery, CdcrUpdateLogTest, PhrasesIdentificationComponentTest, TestSolrConfigHandler, BasicDistributedZkTest, TestCollectionAPI, SolrCoreCheckLockOnStartupTest, NodeMutatorTest, TermsComponentTest, SuggestComponentTest, ZkStateReaderTest, AutoAddReplicasIntegrationTest, TestZkAclsWithHadoopAuth, PeerSyncWithLeaderTest, ScheduledMaintenanceTriggerTest, HdfsNNFailoverTest, DocumentAnalysisRequestHandlerTest, ZkShardTermsTest, TestUtilizeNode, TestExportWriter, TestOmitPositions, TestSimpleTrackingShardHandler, LeaderFailoverAfterPartitionTest, CopyFieldTest, TestPseudoReturnFields, TestHashQParserPlugin, DistribDocExpirationUpdateProcessorTest, TestReplicationHandler, TestJmxIntegration, UnloadDistributedZkTest, TestFieldTypeCollectionResource, UUIDUpdateProcessorFallbackTest, TestManagedResource, HttpTriggerListenerTest, BlobRepositoryCloudTest, SignificantTermsQParserPluginTest, TestPackages, ShardSplitTest, SchemaApiFailureTest, TestUninvertingReader, SolrJmxReporterCloudTest, XCJFQueryTest, TestNestedUpdateProcessor, TestUnInvertedFieldException, PrimUtilsTest, TestSchemaResource, TestInPlaceUpdatesRequiredField, PluginInfoTest, TestDocBasedVersionConstraints, TestSimComputePlanAction, HdfsLockFactoryTest, CachingDirectoryFactoryTest, DefaultValueUpdateProcessorTest, TestTlogReplica]
[junit4] Completed [454/904 (1!)] on J2 in 85.60s, 13 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 53931 lines...]