You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/02/21 18:03:29 UTC
[JENKINS-Experimental-GC] Lucene-Solr-master-Linux
(64bit/jdk-11.0.6) - Build # 25796 - Failure!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25796/
Java: 64bit/jdk-11.0.6 -XX:+UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC
1 tests failed.
FAILED: org.apache.solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest.testAsyncIdBackCompat
Error Message:
Expecting exception
Stack Trace:
java.lang.AssertionError: Expecting exception
at __randomizedtesting.SeedInfo.seed([5241A37D71604CAD:8C7130D1DD8CA8FD]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.apache.solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest.testAsyncIdBackCompat(CollectionsAPIAsyncDistributedZkTest.java:288)
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 14675 lines...]
[junit4] Suite: org.apache.solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest
[junit4] 2> 769050 INFO (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 769050 INFO (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 769050 INFO (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/data-dir-94-001
[junit4] 2> 769050 WARN (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
[junit4] 2> 769050 INFO (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 769051 INFO (SUITE-CollectionsAPIAsyncDistributedZkTest-seed#[5241A37D71604CAD]-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> 769052 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAsyncRequests
[junit4] 2> 769052 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001
[junit4] 2> 769053 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 769054 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 769054 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 769154 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.ZkTestServer start zk server on port:40565
[junit4] 2> 769154 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:40565
[junit4] 2> 769154 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:40565
[junit4] 2> 769154 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 40565
[junit4] 2> 769157 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769164 INFO (zkConnectionManagerCallback-5394-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769164 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769172 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769178 INFO (zkConnectionManagerCallback-5396-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769178 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769179 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769180 INFO (zkConnectionManagerCallback-5398-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769180 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 769303 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.6+10
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 769320 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@e17c199{/solr,null,AVAILABLE}
[junit4] 2> 769322 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@353299bf{/solr,null,AVAILABLE}
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2a558b42{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:41459}
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.e.j.s.Server Started @769605ms
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41459}
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@179a5446{ssl,[ssl, alpn, http/1.1, h2]}{127.0.0.1:39237}
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.e.j.s.Server Started @769605ms
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=39237}
[junit4] 2> 769330 ERROR (jetty-launcher-5399-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-21T17:54:18.983550Z
[junit4] 2> 769330 ERROR (jetty-launcher-5399-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 769330 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-21T17:54:18.983697Z
[junit4] 2> 769337 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769338 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769341 INFO (zkConnectionManagerCallback-5401-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769341 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769341 INFO (zkConnectionManagerCallback-5403-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769341 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769342 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 769350 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 769487 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 769490 WARN (jetty-launcher-5399-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@627f1ae0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769490 WARN (jetty-launcher-5399-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@627f1ae0[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769497 WARN (jetty-launcher-5399-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3bd35287[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769497 WARN (jetty-launcher-5399-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3bd35287[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769498 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40565/solr
[junit4] 2> 769499 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769500 INFO (zkConnectionManagerCallback-5411-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769500 INFO (jetty-launcher-5399-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769530 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 769531 WARN (jetty-launcher-5399-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@407a33cc[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769531 WARN (jetty-launcher-5399-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@407a33cc[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769537 WARN (jetty-launcher-5399-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@478a6f81[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769537 WARN (jetty-launcher-5399-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@478a6f81[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 769538 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:40565/solr
[junit4] 2> 769547 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769547 INFO (zkConnectionManagerCallback-5417-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769547 INFO (jetty-launcher-5399-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769601 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769602 INFO (zkConnectionManagerCallback-5419-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769602 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769648 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769649 INFO (zkConnectionManagerCallback-5421-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769649 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769665 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41459_solr
[junit4] 2> 769665 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.Overseer Overseer (id=72120615306526727-127.0.0.1:41459_solr-n_0000000000) starting
[junit4] 2> 769674 INFO (OverseerStateUpdate-72120615306526727-127.0.0.1:41459_solr-n_0000000000) [n:127.0.0.1:41459_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41459_solr
[junit4] 2> 769675 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39237_solr
[junit4] 2> 769675 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 769676 WARN (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_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> 769678 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:41459_solr as DOWN
[junit4] 2> 769678 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 769678 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41459_solr
[junit4] 2> 769679 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 769679 WARN (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_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> 769682 INFO (zkCallback-5420-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 769684 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 769686 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 769690 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 769701 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39237.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769704 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41459.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769706 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39237.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769706 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39237.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769707 INFO (jetty-launcher-5399-thread-1) [n:127.0.0.1:39237_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node1/.
[junit4] 2> 769709 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41459.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769709 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41459.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769710 INFO (jetty-launcher-5399-thread-2) [n:127.0.0.1:41459_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node2/.
[junit4] 2> 769733 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 769737 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 769738 INFO (zkConnectionManagerCallback-5434-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 769738 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 769738 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 769739 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:40565/solr ready
[junit4] 2> 769750 INFO (qtp548266034-16868) [n:127.0.0.1:41459_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> 769750 INFO (qtp548266034-16868) [n:127.0.0.1:41459_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=0
[junit4] 2> 769751 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params async=be2cbd32-c6fd-4d7f-b411-b790fdc243af&shards=shard1&collection.configName=conf1&name=testAsyncOperations&router.name=implicit&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 769752 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=be2cbd32-c6fd-4d7f-b411-b790fdc243af&shards=shard1&collection.configName=conf1&name=testAsyncOperations&router.name=implicit&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 769752 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 769753 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 769756 INFO (OverseerThreadFactory-4154-thread-1-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection testAsyncOperations
[junit4] 2> 769859 INFO (OverseerStateUpdate-72120615306526727-127.0.0.1:41459_solr-n_0000000000) [n:127.0.0.1:41459_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"testAsyncOperations",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"testAsyncOperations_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:41459/solr",
[junit4] 2> "node_name":"127.0.0.1:41459_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 769967 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=testAsyncOperations&version=2&replicaType=NRT&async=be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571&coreNodeName=core_node2&name=testAsyncOperations_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&wt=javabin} status=0 QTime=0
[junit4] 2> 769967 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&collection=testAsyncOperations&version=2&replicaType=NRT&async=be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571&coreNodeName=core_node2&name=testAsyncOperations_shard1_replica_n1&action=CREATE&numShards=1&shard=shard1&wt=javabin
[junit4] 2> 769970 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 769977 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.IndexSchema [testAsyncOperations_shard1_replica_n1] Schema name=minimal
[junit4] 2> 769978 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 769978 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'testAsyncOperations_shard1_replica_n1' using configuration from configset conf1, trusted=true
[junit4] 2> 769979 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41459.solr.core.testAsyncOperations.shard1.replica_n1' (registry 'solr.core.testAsyncOperations.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 769979 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [[testAsyncOperations_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node2/testAsyncOperations_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node2/./testAsyncOperations_shard1_replica_n1/data/]
[junit4] 2> 769979 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571
[junit4] 2> 769979 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 770000 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 770000 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 770001 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 770001 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 770001 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2e8ea7e7[testAsyncOperations_shard1_replica_n1] main]
[junit4] 2> 770009 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 770009 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 770009 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 770010 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659169836538789888
[junit4] 2> 770012 INFO (searcherExecutor-4163-thread-1-processing-x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 r:core_node2 CREATE n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [testAsyncOperations_shard1_replica_n1] Registered new searcher Searcher@2e8ea7e7[testAsyncOperations_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 770014 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testAsyncOperations/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 770014 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testAsyncOperations/leaders/shard1
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:41459/solr/testAsyncOperations_shard1_replica_n1/
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SyncStrategy https://127.0.0.1:41459/solr/testAsyncOperations_shard1_replica_n1/ has no replicas
[junit4] 2> 770015 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testAsyncOperations/leaders/shard1/leader after winning as /collections/testAsyncOperations/leader_elect/shard1/election/72120615306526727-core_node2-n_0000000000
[junit4] 2> 770016 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:41459/solr/testAsyncOperations_shard1_replica_n1/ shard1
[junit4] 2> 770117 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770117 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770117 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770117 INFO (parallelCoreAdminExecutor-4157-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571 CREATE) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 770218 INFO (zkCallback-5418-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770218 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770218 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770218 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 770753 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 770754 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 770980 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571
[junit4] 2> 770980 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af961629045018571&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 770981 INFO (OverseerThreadFactory-4154-thread-1-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_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> 771754 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 771755 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771755 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :deletestatus with params requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=DELETESTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 771756 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=be2cbd32-c6fd-4d7f-b411-b790fdc243af&action=DELETESTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771756 INFO (TEST-CollectionsAPIAsyncDistributedZkTest.testAsyncRequests-seed#[5241A37D71604CAD]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: testAsyncOperations
[junit4] 2> 771756 INFO (OverseerCollectionConfigSetProcessor-72120615306526727-127.0.0.1:41459_solr-n_0000000000) [n:127.0.0.1:41459_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> 771758 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testAsyncOperations/terms/shard1 to Terms{values={core_node2=1}, version=1}
[junit4] 2> 771758 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [testAsyncOperations_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1659169838370652160), 1 (1659169838371700736), 2 (1659169838371700737), 3 (1659169838371700738), 4 (1659169838371700739), 5 (1659169838371700740), 6 (1659169838371700741), 7 (1659169838371700742), 8 (1659169838371700743), 9 (1659169838371700744), ... (24 adds)]} 0 1
[junit4] 2> 771759 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659169838372749312,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 771759 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@25488040 commitCommandVersion:1659169838372749312
[junit4] 2> 771760 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@b2d3009[testAsyncOperations_shard1_replica_n1] main]
[junit4] 2> 771760 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 771761 INFO (searcherExecutor-4163-thread-1-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 c:testAsyncOperations s:shard1 r:core_node2) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [testAsyncOperations_shard1_replica_n1] Registered new searcher Searcher@b2d3009[testAsyncOperations_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C24:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-28-generic, os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582307661413, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 771762 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [testAsyncOperations_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=testAsyncOperations:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 3
[junit4] 2> 771762 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.S.Request [testAsyncOperations_shard1_replica_n1] webapp=/solr path=/select params={q=*:*&shards=shard1&_stateVer_=testAsyncOperations:3&wt=javabin&version=2} hits=24 status=0 QTime=0
[junit4] 2> 771763 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :reload with params async=3f752d76-d62b-4510-b82b-2e8a8204ecb5&name=testAsyncOperations&action=RELOAD&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 771763 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=3f752d76-d62b-4510-b82b-2e8a8204ecb5&name=testAsyncOperations&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771764 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 771764 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771764 INFO (OverseerThreadFactory-4154-thread-2-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr ] o.a.s.c.a.c.OverseerCollectionMessageHandler Executing Collection Cmd=action=RELOAD, asyncId=3f752d76-d62b-4510-b82b-2e8a8204ecb5
[junit4] 2> 771765 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=testAsyncOperations_shard1_replica_n1&async=3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829&qt=/admin/cores&action=RELOAD&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771765 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829
[junit4] 2> 771765 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 771767 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 771772 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.IndexSchema [testAsyncOperations_shard1_replica_n1] Schema name=minimal
[junit4] 2> 771773 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 771773 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.CoreContainer Reloading SolrCore 'testAsyncOperations_shard1_replica_n1' using configuration from configset conf1
[junit4] 2> 771791 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41459.solr.core.testAsyncOperations.shard1.replica_n1' (registry 'solr.core.testAsyncOperations.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 771791 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [[testAsyncOperations_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node2/testAsyncOperations_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node2/./testAsyncOperations_shard1_replica_n1/data/]
[junit4] 2> 771815 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 771815 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 771816 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@726e1f79[testAsyncOperations_shard1_replica_n1] main]
[junit4] 2> 771817 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 771817 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 771817 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 771822 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 771823 INFO (searcherExecutor-4168-thread-1-processing-x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 r:core_node2 RELOAD n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [testAsyncOperations_shard1_replica_n1] Registered new searcher Searcher@726e1f79[testAsyncOperations_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C24:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-28-generic, os=Linux, java.vendor=AdoptOpenJDK, timestamp=1582307661413, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 771823 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@22c3bb[testAsyncOperations_shard1_replica_n1] main]
[junit4] 2> 771823 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [testAsyncOperations_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@3b77661a
[junit4] 2> 771823 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.testAsyncOperations.shard1.replica_n1, tag=SolrCore@3b77661a
[junit4] 2> 771823 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@230b843b: rootName = solr_41459, domain = solr.core.testAsyncOperations.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.testAsyncOperations.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@5f7306d2
[junit4] 2> 771824 INFO (searcherExecutor-4168-thread-1-processing-x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 r:core_node2 RELOAD n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.c.SolrCore [testAsyncOperations_shard1_replica_n1] Registered new searcher Searcher@22c3bb[testAsyncOperations_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C24:[diagnostics={source=flush, os.arch=amd64, java.runtime.version=11.0.6+10, os.version=5.3.0-28-generic, java.vendor=AdoptOpenJDK, os=Linux, timestamp=1582307661413, java.version=11.0.6, java.vm.version=11.0.6+10, lucene.version=9.0.0}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 771831 INFO (parallelCoreAdminExecutor-4157-thread-2-processing-n:127.0.0.1:41459_solr x:testAsyncOperations_shard1_replica_n1 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829 RELOAD) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard1 r:core_node2 x:testAsyncOperations_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.testAsyncOperations.shard1.leader, tag=SolrCore@3b77661a
[junit4] 2> 772765 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 772765 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 772766 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : 3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829
[junit4] 2> 772766 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5961630950699829&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 772767 INFO (OverseerThreadFactory-4154-thread-2-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000001 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 773765 INFO (OverseerCollectionConfigSetProcessor-72120615306526727-127.0.0.1:41459_solr-n_0000000000) [n:127.0.0.1:41459_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000001 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 773766 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 773766 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 773767 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :deletestatus with params requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=DELETESTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 773767 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=3f752d76-d62b-4510-b82b-2e8a8204ecb5&action=DELETESTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 773768 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createshard with params async=c646fbc7-e713-4f27-ba97-d217842d69ed&action=CREATESHARD&collection=testAsyncOperations&shard=shard2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 773769 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr c:testAsyncOperations ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={async=c646fbc7-e713-4f27-ba97-d217842d69ed&action=CREATESHARD&collection=testAsyncOperations&shard=shard2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 773769 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 773769 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 773769 INFO (OverseerThreadFactory-4154-thread-3-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard2 ] o.a.s.c.a.c.CreateShardCmd Create shard invoked: {
[junit4] 2> "collection":"testAsyncOperations",
[junit4] 2> "shard":"shard2",
[junit4] 2> "async":"c646fbc7-e713-4f27-ba97-d217842d69ed",
[junit4] 2> "operation":"createshard"}
[junit4] 2> 773770 INFO (zkCallback-5418-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 773770 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 773770 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 773770 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 774770 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 774770 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 774771 INFO (OverseerThreadFactory-4154-thread-3-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard2 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:39237_solr for creating new replica of shard shard2 for collection testAsyncOperations
[junit4] 2> 774771 INFO (OverseerThreadFactory-4154-thread-3-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard2 ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 774772 INFO (OverseerStateUpdate-72120615306526727-127.0.0.1:41459_solr-n_0000000000) [n:127.0.0.1:41459_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"testAsyncOperations",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"testAsyncOperations_shard2_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:39237/solr",
[junit4] 2> "node_name":"127.0.0.1:39237_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 774873 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 774873 INFO (zkCallback-5418-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 774873 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 774873 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 774989 INFO (qtp492977974-16895) [n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={async=c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205&qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&name=testAsyncOperations_shard2_replica_n3&action=CREATE&collection=testAsyncOperations&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=0
[junit4] 2> 774989 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 ] o.a.s.h.a.CoreAdminOperation core create command async=c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205&qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf1&name=testAsyncOperations_shard2_replica_n3&action=CREATE&collection=testAsyncOperations&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 774989 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 774990 INFO (qtp492977974-16895) [n:127.0.0.1:39237_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205
[junit4] 2> 774990 INFO (qtp492977974-16895) [n:127.0.0.1:39237_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 775015 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 775023 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.s.IndexSchema [testAsyncOperations_shard2_replica_n3] Schema name=minimal
[junit4] 2> 775024 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 775024 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.CoreContainer Creating SolrCore 'testAsyncOperations_shard2_replica_n3' using configuration from configset conf1, trusted=true
[junit4] 2> 775025 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_39237.solr.core.testAsyncOperations.shard2.replica_n3' (registry 'solr.core.testAsyncOperations.shard2.replica_n3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a3c789b
[junit4] 2> 775025 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SolrCore [[testAsyncOperations_shard2_replica_n3] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node1/testAsyncOperations_shard2_replica_n3], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.CollectionsAPIAsyncDistributedZkTest_5241A37D71604CAD-001/tempDir-001/node1/./testAsyncOperations_shard2_replica_n3/data/]
[junit4] 2> 775057 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 775057 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 775058 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 775058 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 775059 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@10a020c6[testAsyncOperations_shard2_replica_n3] main]
[junit4] 2> 775059 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 775060 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 775060 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 775060 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659169841834098688
[junit4] 2> 775062 INFO (searcherExecutor-4172-thread-1-processing-x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 r:core_node4 CREATE n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SolrCore [testAsyncOperations_shard2_replica_n3] Registered new searcher Searcher@10a020c6[testAsyncOperations_shard2_replica_n3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 775079 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/testAsyncOperations/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 775079 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/testAsyncOperations/leaders/shard2
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:39237/solr/testAsyncOperations_shard2_replica_n3/
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.SyncStrategy https://127.0.0.1:39237/solr/testAsyncOperations_shard2_replica_n3/ has no replicas
[junit4] 2> 775080 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/testAsyncOperations/leaders/shard2/leader after winning as /collections/testAsyncOperations/leader_elect/shard2/election/72120615306526728-core_node4-n_0000000000
[junit4] 2> 775082 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:39237/solr/testAsyncOperations_shard2_replica_n3/ shard2
[junit4] 2> 775234 INFO (zkCallback-5418-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775234 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775234 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775234 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775234 INFO (zkCallback-5420-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775235 INFO (zkCallback-5420-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775236 INFO (parallelCoreAdminExecutor-4155-thread-1-processing-n:127.0.0.1:39237_solr x:testAsyncOperations_shard2_replica_n3 c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205 CREATE) [n:127.0.0.1:39237_solr c:testAsyncOperations s:shard2 r:core_node4 x:testAsyncOperations_shard2_replica_n3 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 775247 INFO (zkCallback-5420-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775338 INFO (zkCallback-5420-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775338 INFO (zkCallback-5420-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775338 INFO (zkCallback-5420-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775339 INFO (zkCallback-5420-thread-4) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775340 INFO (zkCallback-5418-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775340 INFO (zkCallback-5418-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775340 INFO (zkCallback-5418-thread-5) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775340 INFO (zkCallback-5418-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testAsyncOperations/state.json] for collection [testAsyncOperations] has occurred - updating... (live nodes size: [2])
[junit4] 2> 775771 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 775772 INFO (qtp548266034-16870) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 775992 INFO (qtp492977974-16895) [n:127.0.0.1:39237_solr ] o.a.s.h.a.CoreAdminOperation Checking request status for : c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205
[junit4] 2> 775992 INFO (qtp492977974-16895) [n:127.0.0.1:39237_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&requestid=c646fbc7-e713-4f27-ba97-d217842d69ed961634158950205&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 775993 INFO (OverseerThreadFactory-4154-thread-3-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard2 ] o.a.s.c.a.c.CreateShardCmd Finished create command on all shards for collection: testAsyncOperations
[junit4] 2> 775993 INFO (OverseerThreadFactory-4154-thread-3-processing-n:127.0.0.1:41459_solr) [n:127.0.0.1:41459_solr c:testAsyncOperations s:shard2 ] 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> 776775 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :requeststatus with params requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 776777 INFO (qtp548266034-16868) [n:127.0.0.1:41459_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={requestid=c646fbc7-e713-4f27-ba97-d217842d69ed&action=REQUESTSTATUS&wt=javabin&version=2} status=0 QTime=2
[junit
[...truncated too long message...]
ib/netty-common-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/netty-handler-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/netty-resolver-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/netty-transport-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/netty-transport-native-epoll-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/netty-transport-native-unix-common-4.1.29.Final.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/slf4j-api-1.7.24.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/stax2-api-3.1.4.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/woodstox-core-asl-4.4.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/zookeeper-3.5.5.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/solrj/lib/zookeeper-jute-3.5.5.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/http2-common-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/http2-hpack-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/http2-server-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/javax.servlet-api-3.1.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-alpn-java-server-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-alpn-server-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-continuation-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-deploy-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-http-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-io-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-jmx-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-rewrite-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-security-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-server-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-servlet-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-servlets-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-util-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-webapp-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/jetty-xml-9.4.24.v20191120.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/metrics-core-4.1.2.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/metrics-graphite-4.1.2.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/metrics-jetty9-4.1.2.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/metrics-jmx-4.1.2.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/lib/metrics-jvm-4.1.2.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/example/example-DIH/solr/db/lib/hsqldb-2.4.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/core/classes/java:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/test-framework/lib/hamcrest-core-1.3.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/test-framework/lib/junit-4.12.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/test-framework/lib/randomizedtesting-runner-2.7.6.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/antlr4-runtime-4.5.1-1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/byte-buddy-1.9.3.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/commons-compress-1.19.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/commons-logging-1.1.3.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/commons-text-1.6.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/hadoop-common-3.2.0-tests.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/hadoop-hdfs-3.2.0-tests.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/hadoop-hdfs-3.2.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/hadoop-minikdc-3.2.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/jersey-servlet-1.19.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-admin-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-client-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-common-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-crypto-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-identity-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-server-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerb-simplekdc-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerby-config-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerby-kdc-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/kerby-util-1.0.1.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/mockito-core-2.23.4.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/objenesis-2.6.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/core/test-lib/opentracing-mock-0.33.0.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/analysis/icu/lucene-analyzers-icu-9.0.0-SNAPSHOT.jar:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/contrib/solr-analysis-extras/classes/java:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/queryparser/classes/test:/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/build/backward-codecs/classes/test:/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/contrib/analysis-extras/lib/icu4j-62.2.jar:/home/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.7.6.jar com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -eventsfile /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/temp/junit4-J5-20200221_174129_35215678541046306569410.events @/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/temp/junit4-J5-20200221_174129_3523105082118221028988.suites -stdin
[junit4] ERROR: JVM J5 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. See process stdout at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/temp/junit4-J5-20200221_174129_35216797987655651630905.sysout
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1542)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:123)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:997)
[junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:994)
[junit4] at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
[junit4] at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
[junit4] at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
[junit4] at java.base/java.lang.Thread.run(Thread.java:834)
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:635: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:579: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/build.xml:59: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build.xml:232: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/common-build.xml:549: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/common-build.xml:1516: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-master-Linux/lucene/common-build.xml:1043: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. See process stdout at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/temp/junit4-J5-20200221_174129_35216797987655651630905.sysout
Total time: 32 minutes 23 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[WARNINGS] Skipping publisher since build result is FAILURE
Recording test results
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
Setting ANT_1_8_2_HOME=/home/jenkins/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2
[JENKINS-EA] Lucene-Solr-master-Linux (64bit/jdk-15-ea+9) - Build #
25797 - Still unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25797/
Java: 64bit/jdk-15-ea+9 -XX:+UseCompressedOops -XX:+UseG1GC
1 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:43831/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:43831/solr/.system]
at __randomizedtesting.SeedInfo.seed([2F0799A74CE3A10C:5FF23A0E2C2B087A]: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:564)
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:832)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:43831/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/sun.nio.ch.NioSocketImpl.timedRead(NioSocketImpl.java:283)
at java.base/sun.nio.ch.NioSocketImpl.implRead(NioSocketImpl.java:309)
at java.base/sun.nio.ch.NioSocketImpl.read(NioSocketImpl.java:350)
at java.base/sun.nio.ch.NioSocketImpl$1.read(NioSocketImpl.java:803)
at java.base/java.net.Socket$SocketInputStream.read(Socket.java:982)
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 13934 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 232573 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/server/solr/configsets/_default/conf'
[junit4] 2> 232573 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/data-dir-46-001
[junit4] 2> 232573 WARN (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
[junit4] 2> 232573 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 232574 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 232574 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 232574 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001
[junit4] 2> 232574 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 232574 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 232574 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 232674 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:38977
[junit4] 2> 232674 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:38977
[junit4] 2> 232674 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38977
[junit4] 2> 232674 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38977
[junit4] 2> 232686 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 232694 INFO (zkConnectionManagerCallback-1283-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 232694 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 232696 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 232697 INFO (zkConnectionManagerCallback-1285-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 232697 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 232697 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 232702 INFO (zkConnectionManagerCallback-1287-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 232702 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 15-ea+9-264
[junit4] 2> 232812 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 15-ea+9-264
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@37b7743b{/solr,null,AVAILABLE}
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@66399f00{/solr,null,AVAILABLE}
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@409dd390{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:43831}
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.e.j.s.Server Started @232830ms
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3f7f0e5{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:42163}
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43831}
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.e.j.s.Server Started @232830ms
[junit4] 2> 232813 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=42163}
[junit4] 2> 232814 ERROR (jetty-launcher-1288-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 232814 ERROR (jetty-launcher-1288-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-21T19:43:43.131112Z
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr
[junit4] 2> 232814 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-21T19:43:43.131171Z
[junit4] 2> 232815 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 232815 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 232819 INFO (zkConnectionManagerCallback-1291-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 232819 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 232819 INFO (zkConnectionManagerCallback-1292-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 232819 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 232820 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 232820 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 233041 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 233042 WARN (jetty-launcher-1288-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3c1c79ec[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233042 WARN (jetty-launcher-1288-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3c1c79ec[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233064 WARN (jetty-launcher-1288-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@315fdba3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233064 WARN (jetty-launcher-1288-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@315fdba3[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233065 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38977/solr
[junit4] 2> 233076 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 233077 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233077 WARN (jetty-launcher-1288-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@15fc0a72[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233077 WARN (jetty-launcher-1288-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@15fc0a72[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233078 INFO (zkConnectionManagerCallback-1300-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233078 INFO (jetty-launcher-1288-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233079 WARN (jetty-launcher-1288-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@b8321b6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233079 WARN (jetty-launcher-1288-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@b8321b6[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 233080 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:38977/solr
[junit4] 2> 233089 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233090 INFO (zkConnectionManagerCallback-1306-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233090 INFO (jetty-launcher-1288-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233184 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233186 INFO (zkConnectionManagerCallback-1308-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233186 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233248 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:42163_solr
[junit4] 2> 233249 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.Overseer Overseer (id=72121045496692743-127.0.0.1:42163_solr-n_0000000000) starting
[junit4] 2> 233251 INFO (OverseerStateUpdate-72121045496692743-127.0.0.1:42163_solr-n_0000000000) [n:127.0.0.1:42163_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:42163_solr
[junit4] 2> 233258 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42163_solr
[junit4] 2> 233261 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 233261 WARN (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_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> 233262 INFO (zkCallback-1307-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 233270 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 233282 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233282 INFO (zkConnectionManagerCallback-1314-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233282 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233286 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 233286 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42163.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233288 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:43831_solr as DOWN
[junit4] 2> 233290 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 233290 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43831_solr
[junit4] 2> 233291 INFO (zkCallback-1307-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 233291 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 233292 WARN (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_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> 233292 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42163.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233292 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_42163.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233293 INFO (jetty-launcher-1288-thread-1) [n:127.0.0.1:42163_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node1/.
[junit4] 2> 233298 INFO (zkCallback-1313-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 233302 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 233319 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233325 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233325 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233326 INFO (jetty-launcher-1288-thread-2) [n:127.0.0.1:43831_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/.
[junit4] 2> 233341 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 233342 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233343 INFO (zkConnectionManagerCallback-1323-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233343 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233343 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 233344 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38977/solr ready
[junit4] 2> 233355 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 233357 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 233358 INFO (zkConnectionManagerCallback-1328-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 233358 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 233358 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 233359 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:38977/solr ready
[junit4] 2> 233362 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 233367 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 233368 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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:43831_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 233370 INFO (OverseerThreadFactory-1438-thread-2-processing-n:127.0.0.1:42163_solr) [n:127.0.0.1:42163_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 233370 INFO (OverseerCollectionConfigSetProcessor-72121045496692743-127.0.0.1:42163_solr-n_0000000000) [n:127.0.0.1:42163_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> 233472 WARN (OverseerThreadFactory-1438-thread-2-processing-n:127.0.0.1:42163_solr) [n:127.0.0.1:42163_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> 233474 INFO (OverseerStateUpdate-72121045496692743-127.0.0.1:42163_solr-n_0000000000) [n:127.0.0.1:42163_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43831/solr",
[junit4] 2> "node_name":"127.0.0.1:43831_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 233475 INFO (OverseerStateUpdate-72121045496692743-127.0.0.1:42163_solr-n_0000000000) [n:127.0.0.1:42163_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:43831/solr",
[junit4] 2> "node_name":"127.0.0.1:43831_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 233678 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233678 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233688 WARN (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
[junit4] 2> 233688 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233688 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233698 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233698 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233699 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233699 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233702 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233702 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233707 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 233708 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 233708 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233708 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233709 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/.system_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/./.system_shard1_replica_n2/data/]
[junit4] 2> 233710 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 233710 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233710 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 233710 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/.system_shard1_replica_n1], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/./.system_shard1_replica_n1/data/]
[junit4] 2> 233748 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233748 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233748 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233748 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233750 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233750 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233750 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 233750 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 233751 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@50585c95[.system_shard1_replica_n1] main]
[junit4] 2> 233751 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@daea92e[.system_shard1_replica_n2] main]
[junit4] 2> 233753 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233753 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233754 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233754 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233754 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233754 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233754 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 233755 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233757 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233757 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233758 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 3 ms
[junit4] 2> 233758 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233758 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233758 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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 1659176719823667200
[junit4] 2> 233758 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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 1659176719823667200
[junit4] 2> 233760 INFO (searcherExecutor-1448-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:43831_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@50585c95[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 233760 INFO (searcherExecutor-1447-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_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@daea92e[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 233761 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 233761 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 233761 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 233761 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233763 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233763 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233763 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:43831/solr/.system_shard1_replica_n1/
[junit4] 2> 233764 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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=http://127.0.0.1:43831/solr START replicas=[http://127.0.0.1:43831/solr/.system_shard1_replica_n2/] nUpdates=100
[junit4] 2> 233764 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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=http://127.0.0.1:43831/solr DONE. We have no versions. sync failed.
[junit4] 2> 233765 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 233765 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233765 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233765 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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/72121045496692744-core_node3-n_0000000000
[junit4] 2> 233766 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 233867 INFO (zkCallback-1313-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> 233867 INFO (zkCallback-1313-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> 233867 INFO (zkCallback-1313-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> 233867 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 233868 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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=190
[junit4] 2> 233969 INFO (zkCallback-1313-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> 233969 INFO (zkCallback-1313-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> 233969 INFO (zkCallback-1313-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> 233969 INFO (zkCallback-1313-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> 234770 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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=1092
[junit4] 2> 234772 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 234871 INFO (zkCallback-1313-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> 234871 INFO (zkCallback-1313-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> 234871 INFO (zkCallback-1313-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> 234871 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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:43831_solr&wt=javabin&version=2} status=0 QTime=1503
[junit4] 2> 234872 INFO (zkCallback-1313-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> 234872 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[2F0799A74CE3A10C]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 234894 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 234920 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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=http://127.0.0.1:43831/solr/.system_shard1_replica_n1/&wt=javabin&version=2}{add=[1706946fe25Thyjs62z3necexnieacmwhizc (1659176720993878016)]} 0 2
[junit4] 2> 234920 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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=[1706946fe25Thyjs62z3necexnieacmwhizc (1659176720993878016)]} 0 47
[junit4] 2> 234922 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659176721043161088,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 234922 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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@333be001 commitCommandVersion:1659176721043161088
[junit4] 2> 234922 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659176721044209664,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 234922 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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@39f36a0d commitCommandVersion:1659176721044209664
[junit4] 2> 234934 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@17f013c9[.system_shard1_replica_n1] main]
[junit4] 2> 234935 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 234936 INFO (searcherExecutor-1448-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:43831_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@17f013c9[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1582314225247, java.vendor=Oracle Corporation, os=Linux, os.version=5.3.0-28-generic, java.runtime.version=15-ea+9-264, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=15-ea+9-264, java.version=15-ea}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 234938 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@74e052fa[.system_shard1_replica_n2] main]
[junit4] 2> 234939 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 234940 INFO (searcherExecutor-1447-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_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@74e052fa[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1582314225248, java.vendor=Oracle Corporation, os=Linux, os.version=5.3.0-28-generic, java.runtime.version=15-ea+9-264, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=15-ea+9-264, java.version=15-ea}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 234941 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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=http://127.0.0.1:43831/solr/.system_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 18
[junit4] 2> 234943 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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:4&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 22
[junit4] 2> 234947 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 234947 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 234950 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 234956 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 234957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 234960 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 234965 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 234966 INFO (Thread-796) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n2
[junit4] 2> 234967 INFO (Thread-796) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n2
[junit4] 2> 234971 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 234978 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 234981 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 234981 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 235011 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 235012 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/.system_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/./.system_shard1_replica_n2/data/]
[junit4] 2> 235044 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235044 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 235048 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@168863ee[.system_shard1_replica_n2] main]
[junit4] 2> 235049 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235049 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235049 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235050 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235050 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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> 235052 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 235054 INFO (searcherExecutor-1457-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_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@168863ee[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1582314225248, java.vendor=Oracle Corporation, os=Linux, os.version=5.3.0-28-generic, java.runtime.version=15-ea+9-264, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=15-ea+9-264, java.version=15-ea}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 235055 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@33dec853[.system_shard1_replica_n2] main]
[junit4] 2> 235057 INFO (searcherExecutor-1457-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_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@33dec853[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={timestamp=1582314225248, os=Linux, java.vendor=Oracle Corporation, os.version=5.3.0-28-generic, java.runtime.version=15-ea+9-264, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=15-ea+9-264, java.version=15-ea}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 235057 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 235059 INFO (Thread-796) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 235069 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235069 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235069 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 235070 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235073 INFO (Thread-796) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 235074 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235075 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235075 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235075 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235075 INFO (Thread-796) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 235075 INFO (Thread-796) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n2' using configuration from configset .system
[junit4] 2> 235075 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235076 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235076 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235076 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235078 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235078 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235078 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235078 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235079 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235079 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235079 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235079 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235079 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235079 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235079 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235079 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235082 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235082 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235082 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235082 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235082 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235083 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235083 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235083 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235083 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235083 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235083 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235083 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235084 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235084 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235084 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235084 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235088 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235088 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235088 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235089 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235089 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235089 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235089 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235089 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235089 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235090 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235090 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235090 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235090 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235090 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235090 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235090 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235090 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235091 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235091 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235091 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235094 INFO (Thread-796) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43831.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@2da1e9d3
[junit4] 2> 235094 INFO (Thread-796) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/.system_shard1_replica_n2], dataDir=[/home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001/tempDir-001/node2/./.system_shard1_replica_n2/data/]
[junit4] 2> 235099 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235099 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235099 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235099 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235103 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235103 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_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> 235103 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235103 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235103 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235103 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_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> 235104 INFO (qtp1314530347-4321) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235104 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235104 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235104 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_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> 235104 INFO (qtp1314530347-4338) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 235104 ERROR (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 235104 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 235105 INFO (qtp1314530347-4330) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReade
[...truncated too long message...]
lica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:43831/solr/.system_shard1_replica_n1
[junit4] 2> 368326 WARN (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:43831/solr/.system_shard1_replica_n1
[junit4] 2> 369350 WARN (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:43831/solr/.system_shard1_replica_n1
[junit4] 2> 370378 WARN (managedSchemaExecutor-1461-thread-1-processing-n:127.0.0.1:43831_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Failed to get /schema/zkversion from http://127.0.0.1:43831/solr/.system_shard1_replica_n1/ due to: java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://127.0.0.1:43831/solr/.system_shard1_replica_n1
[junit4] 2> 370956 INFO (httpUriRequest-345709-thread-1-processing-x:.system_shard1_replica_n2 r:core_node4 n:127.0.0.1:43831_solr http:////127.0.0.1:43831//solr//.system_shard1_replica_n1 c:.system s:shard1) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.h.i.e.RetryExec I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:43831: Socket closed
[junit4] 2> 370957 INFO (httpUriRequest-345709-thread-1-processing-x:.system_shard1_replica_n2 r:core_node4 n:127.0.0.1:43831_solr http:////127.0.0.1:43831//solr//.system_shard1_replica_n1 c:.system s:shard1) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.h.i.e.RetryExec Retrying request to {}->http://127.0.0.1:43831
[junit4] 2> 370957 WARN (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Core core_node4 was interrupted waiting for schema version 2 to propagate to 1 replicas for collection .system
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Took 135901.0ms for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=136003
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@6f144c91
[junit4] 2> 370957 WARN (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.SolrMetricManager Interrupted while trying to obtain lock to modify reporters registry: solr.core..system.shard1.replica_n2
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection..system.shard1.leader, tag=SolrCore@6f144c91
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() .
[junit4] 2> 370957 INFO (qtp1314530347-4329) [n:127.0.0.1:43831_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@3d67766a commitCommandVersion:0
[junit4] 2> 370958 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 371161 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 7 /solr/clusterprops.json
[junit4] 2> 7 /solr/aliases.json
[junit4] 2> 5 /solr/collections/.system/terms/shard1
[junit4] 2> 4 /solr/configs/.system/managed-schema
[junit4] 2> 2 /solr/configs/.system
[junit4] 2> 2 /solr/packages.json
[junit4] 2> 2 /solr/security.json
[junit4] 2> 2 /solr/collections/.system/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 19 /solr/collections/.system/state.json
[junit4] 2> 7 /solr/clusterstate.json
[junit4] 2> 6 /solr/aliases.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 22 /solr/overseer/queue
[junit4] 2> 18 /solr/collections
[junit4] 2> 11 /solr/live_nodes
[junit4] 2> 11 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 371162 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:38977
[junit4] 2> 371162 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:38977
[junit4] 2> 371162 INFO (SUITE-SystemCollectionCompatTest-seed#[2F0799A74CE3A10C]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 38977
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-master-Linux/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_2F0799A74CE3A10C-001
[junit4] 2> Feb 21, 2020 7:46:01 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {id=PostingsFormat(name=LuceneFixedGap), type=PostingsFormat(name=MockRandom)}, docValues:{timestamp_l=DocValuesFormat(name=Lucene80), _version_=DocValuesFormat(name=Asserting), time_l=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Asserting)}, maxPointsInLeafNode=1472, maxMBSortInHeap=5.668588001931112, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@6e38fdc), locale=sw-UG, timezone=America/St_Lucia
[junit4] 2> NOTE: Linux 5.3.0-28-generic amd64/Oracle Corporation 15-ea (64-bit)/cpus=16,threads=1,free=61490328,total=444596224
[junit4] 2> NOTE: All tests run in this JVM: [SliceStateTest, TestClusterProperties, SolrCoreTest, SolrLogAuditLoggerPluginTest, WordBreakSolrSpellCheckerTest, QueryResultKeyTest, TestPostingsSolrHighlighter, TestReplicationHandlerBackup, TestSimNodeAddedTrigger, TestAnalyzedSuggestions, EchoParamsTest, TestLRUStatsCache, RulesTest, NoCacheHeaderTest, TestQueryingOnDownCollection, TestGraphMLResponseWriter, TestPhraseSuggestions, IndexSizeTriggerMixedBoundsTest, TestSolrCoreParser, HdfsChaosMonkeyNothingIsSafeTest, DistributedFacetPivotWhiteBoxTest, ZkFailoverTest, QueryElevationComponentTest, HttpPartitionTest, TestCharFilters, TestJsonFacetsStatsParsing, NodeAddedTriggerTest, TestDocTermOrds, DimensionalRoutedAliasUpdateProcessorTest, TriggerCooldownIntegrationTest, TestIndexSearcher, TestDistributedStatsComponentCardinality, SystemCollectionCompatTest]
[junit4] Completed [335/904 (1!)] on J0 in 139.61s, 1 test, 1 error <<< FAILURES!
[...truncated 46805 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-Linux/25797/consoleText
[repro] Revision: bc41f25cc9f98793bd9ae20853373d8275048f83
[repro] Ant options: "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC"
[repro] Repro line: ant test -Dtestcase=SystemCollectionCompatTest -Dtests.method=testBackCompat -Dtests.seed=2F0799A74CE3A10C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sw-UG -Dtests.timezone=America/St_Lucia -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] SystemCollectionCompatTest
[repro] ant compile-test
[...truncated 3146 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=5 -Dtests.class="*.SystemCollectionCompatTest" -Dtests.showOutput=onerror "-Dargs=-XX:+UseCompressedOops -XX:+UseG1GC" -Dtests.seed=2F0799A74CE3A10C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=sw-UG -Dtests.timezone=America/St_Lucia -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[...truncated 81 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.SystemCollectionCompatTest
[repro] Exiting with code 0
[...truncated 43 lines...]