You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2019/07/24 15:01:36 UTC
[JENKINS] Lucene-Solr-Tests-8.x - Build # 311 - Still Unstable
Build: https://builds.apache.org/job/Lucene-Solr-Tests-8.x/311/
2 tests failed.
FAILED: org.apache.solr.cloud.api.collections.SplitByPrefixTest.doTest
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([B980178A30F46BB3:1EC4AF2E5D4F780A]:0)
at org.junit.Assert.fail(Assert.java:86)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.junit.Assert.assertTrue(Assert.java:52)
at org.apache.solr.cloud.api.collections.SplitByPrefixTest.doTest(SplitByPrefixTest.java:222)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at 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:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
FAILED: org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth
Error Message:
expected:<401> but was:<400>
Stack Trace:
java.lang.AssertionError: expected:<401> but was:<400>
at __randomizedtesting.SeedInfo.seed([B980178A30F46BB3:5EE619894A7E8C9]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:645)
at org.junit.Assert.assertEquals(Assert.java:631)
at org.apache.solr.security.BasicAuthIntegrationTest.testBasicAuth(BasicAuthIntegrationTest.java:151)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:938)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:974)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:988)
at 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:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:947)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:832)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:883)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:894)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:748)
Build Log:
[...truncated 13749 lines...]
[junit4] Suite: org.apache.solr.cloud.api.collections.SplitByPrefixTest
[junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/init-core-data-001
[junit4] 2> 470943 WARN (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 470943 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 470945 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, ssl=NaN, value=NaN, clientAuth=NaN)
[junit4] 2> 470946 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 470946 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001
[junit4] 2> 470946 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 470947 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 470947 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 471047 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:32867
[junit4] 2> 471047 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:32867
[junit4] 2> 471047 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 32867
[junit4] 2> 471049 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471051 INFO (zkConnectionManagerCallback-3594-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471052 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471055 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471056 INFO (zkConnectionManagerCallback-3596-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471056 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471057 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471058 INFO (zkConnectionManagerCallback-3598-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471058 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471168 WARN (jetty-launcher-3599-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time
[junit4] 2> 471169 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0)
[junit4] 2> 471169 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 471169 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.Server jetty-9.4.19.v20190610; built: 2019-06-10T16:30:51.723Z; git: afcf563148970e98786327af5e07c261fda175d3; jvm 1.8.0_191-b12
[junit4] 2> 471171 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 471171 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 471171 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 471171 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@636b6497{/solr,null,AVAILABLE}
[junit4] 2> 471172 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@234239d0{SSL,[ssl, http/1.1]}{127.0.0.1:45201}
[junit4] 2> 471172 INFO (jetty-launcher-3599-thread-1) [ ] o.e.j.s.Server Started @471347ms
[junit4] 2> 471172 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=45201}
[junit4] 2> 471172 ERROR (jetty-launcher-3599-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 471172 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 471173 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 8.3.0
[junit4] 2> 471173 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 471173 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 471173 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-07-24T13:53:45.569Z
[junit4] 2> 471174 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471175 INFO (zkConnectionManagerCallback-3601-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471175 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471176 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 471449 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 471449 WARN (jetty-launcher-3599-thread-1) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 471450 WARN (jetty-launcher-3599-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3361d63a[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 471450 WARN (jetty-launcher-3599-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3361d63a[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 471453 WARN (jetty-launcher-3599-thread-1) [ ] o.a.s.c.s.i.Http2SolrClient Create Http2SolrClient with HTTP/1.1 transport since Java 8 or lower versions does not support SSL + HTTP/2
[junit4] 2> 471454 WARN (jetty-launcher-3599-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@77182c9e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 471454 WARN (jetty-launcher-3599-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@77182c9e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 471455 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:32867/solr
[junit4] 2> 471456 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471457 INFO (zkConnectionManagerCallback-3608-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471457 INFO (jetty-launcher-3599-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471560 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471562 INFO (zkConnectionManagerCallback-3610-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471562 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471661 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:45201_solr
[junit4] 2> 471662 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.Overseer Overseer (id=72083678759485445-127.0.0.1:45201_solr-n_0000000000) starting
[junit4] 2> 471669 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471671 INFO (zkConnectionManagerCallback-3617-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471671 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471676 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:32867/solr ready
[junit4] 2> 471678 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:45201_solr
[junit4] 2> 471681 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45201_solr
[junit4] 2> 471683 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 471683 INFO (zkCallback-3616-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 471685 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.LibListener clusterprops.json changed , version 0
[junit4] 2> 471712 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 471750 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 471762 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 471762 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 471763 INFO (jetty-launcher-3599-thread-1) [n:127.0.0.1:45201_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/.
[junit4] 2> 471788 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 471790 INFO (zkConnectionManagerCallback-3623-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 471790 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 471791 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 471793 INFO (SUITE-SplitByPrefixTest-seed#[B980178A30F46BB3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:32867/solr ready
[junit4] 2> 471818 INFO (TEST-SplitByPrefixTest.doTest-seed#[B980178A30F46BB3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTest
[junit4] 2> 471832 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&maxShardsPerNode=100&name=c1&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 471836 INFO (OverseerThreadFactory-2235-thread-1-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection c1
[junit4] 2> 471946 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"c1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"c1_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 472152 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=c1_shard1_replica_n1&action=CREATE&numShards=1&collection=c1&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 472152 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 473168 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 473187 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.IndexSchema [c1_shard1_replica_n1] Schema name=minimal
[junit4] 2> 473192 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 473192 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'c1_shard1_replica_n1' using configuration from collection c1, trusted=true
[junit4] 2> 473196 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.core.c1.shard1.replica_n1' (registry 'solr.core.c1.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 473196 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SolrCore [[c1_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/c1_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/./c1_shard1_replica_n1/data/]
[junit4] 2> 473272 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 473272 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 473274 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 473274 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 473276 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@477c25c7[c1_shard1_replica_n1] main]
[junit4] 2> 473278 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 473279 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 473279 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf/managed-schema
[junit4] 2> 473280 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 473282 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 473285 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1639948146632032256
[junit4] 2> 473289 INFO (searcherExecutor-2240-thread-1-processing-n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 c:c1 s:shard1 r:core_node2) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SolrCore [c1_shard1_replica_n1] Registered new searcher Searcher@477c25c7[c1_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 473293 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/c1/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 473293 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/c1/leaders/shard1
[junit4] 2> 473298 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 473298 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 473298 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45201/solr/c1_shard1_replica_n1/
[junit4] 2> 473298 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 473299 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.SyncStrategy https://127.0.0.1:45201/solr/c1_shard1_replica_n1/ has no replicas
[junit4] 2> 473299 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/c1/leaders/shard1/leader after winning as /collections/c1/leader_elect/shard1/election/72083678759485445-core_node2-n_0000000000
[junit4] 2> 473301 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:45201/solr/c1_shard1_replica_n1/ shard1
[junit4] 2> 473404 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473404 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473406 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 473409 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=c1_shard1_replica_n1&action=CREATE&numShards=1&collection=c1&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1257
[junit4] 2> 473413 INFO (qtp700076704-8951) [n:127.0.0.1:45201_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> 473509 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473509 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473510 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473510 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&maxShardsPerNode=100&name=c1&nrtReplicas=1&action=CREATE&numShards=1&wt=javabin&version=2} status=0 QTime=1678
[junit4] 2> 473514 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :splitshard with params action=SPLITSHARD&splitByPrefix=true&numSubShards=2&collection=c1&shard=shard1&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 473517 INFO (OverseerCollectionConfigSetProcessor-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_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> 473520 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace&wt=javabin&version=2&group=solr.node} status=0 QTime=0
[junit4] 2> 473521 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.c1.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0
[junit4] 2> 473524 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.SplitShardCmd Requesting split ranges from replica core_node2 as part of slice shard1 of collection c1 on core_node2:{
[junit4] 2> "core":"c1_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 473524 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=c1_shard1_replica_n1&qt=/admin/cores&getRanges=true&action=SPLIT&numSubShards=2&wt=javabin&version=2&splitMethod=rewrite} status=0 QTime=0
[junit4] 2> 473525 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.SplitShardCmd numSubShards set at: 2
[junit4] 2> 473644 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473644 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 473644 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474530 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:45201_solr for creating new replica of shard shard1_0 for collection c1
[junit4] 2> 474530 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 474532 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"c1",
[junit4] 2> "shard":"shard1_0",
[junit4] 2> "core":"c1_shard1_0_replica_n3",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 474635 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474635 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474635 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474768 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&name=c1_shard1_0_replica_n3&action=CREATE&collection=c1&shard=shard1_0&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 474780 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 474799 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.IndexSchema [c1_shard1_0_replica_n3] Schema name=minimal
[junit4] 2> 474804 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 474804 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.CoreContainer Creating SolrCore 'c1_shard1_0_replica_n3' using configuration from collection c1, trusted=true
[junit4] 2> 474805 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.core.c1.shard1_0.replica_n3' (registry 'solr.core.c1.shard1_0.replica_n3') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 474805 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SolrCore [[c1_shard1_0_replica_n3] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/c1_shard1_0_replica_n3], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/./c1_shard1_0_replica_n3/data/]
[junit4] 2> 474873 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474873 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474873 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 474877 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 474877 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 474879 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 474879 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 474889 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@997e23b[c1_shard1_0_replica_n3] main]
[junit4] 2> 474897 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 474898 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 474898 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf/managed-schema
[junit4] 2> 474899 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 474900 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 474900 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1639948148325482496
[junit4] 2> 474902 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 474903 INFO (searcherExecutor-2245-thread-1-processing-n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 c:c1 s:shard1_0 r:core_node5) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SolrCore [c1_shard1_0_replica_n3] Registered new searcher Searcher@997e23b[c1_shard1_0_replica_n3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 474911 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/c1/terms/shard1_0 to Terms{values={core_node5=0}, version=0}
[junit4] 2> 474911 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/c1/leaders/shard1_0
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45201/solr/c1_shard1_0_replica_n3/
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SyncStrategy https://127.0.0.1:45201/solr/c1_shard1_0_replica_n3/ has no replicas
[junit4] 2> 474916 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/c1/leaders/shard1_0/leader after winning as /collections/c1/leader_elect/shard1_0/election/72083678759485445-core_node5-n_0000000000
[junit4] 2> 474918 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:45201/solr/c1_shard1_0_replica_n3/ shard1_0
[junit4] 2> 475020 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 475020 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 475020 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 475021 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 475023 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node5&collection.configName=conf&name=c1_shard1_0_replica_n3&action=CREATE&collection=c1&shard=shard1_0&wt=javabin&version=2&replicaType=NRT} status=0 QTime=255
[junit4] 2> 475130 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 475130 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 475130 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476028 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:45201_solr for creating new replica of shard shard1_1 for collection c1
[junit4] 2> 476028 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 476031 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"addreplica",
[junit4] 2> "collection":"c1",
[junit4] 2> "shard":"shard1_1",
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "type":"NRT"}
[junit4] 2> 476134 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476134 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476134 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476234 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&name=c1_shard1_1_replica_n4&action=CREATE&collection=c1&shard=shard1_1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 476245 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 8.3.0
[junit4] 2> 476256 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.IndexSchema [c1_shard1_1_replica_n4] Schema name=minimal
[junit4] 2> 476262 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 476262 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.CoreContainer Creating SolrCore 'c1_shard1_1_replica_n4' using configuration from collection c1, trusted=true
[junit4] 2> 476262 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_45201.solr.core.c1.shard1_1.replica_n4' (registry 'solr.core.c1.shard1_1.replica_n4') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@297e85eb
[junit4] 2> 476263 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SolrCore [[c1_shard1_1_replica_n4] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/c1_shard1_1_replica_n4], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/build/solr-core/test/J2/temp/solr.cloud.api.collections.SplitByPrefixTest_B980178A30F46BB3-001/tempDir-001/node1/./c1_shard1_1_replica_n4/data/]
[junit4] 2> 476327 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 476327 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 476328 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 476328 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 476330 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6447ad6e[c1_shard1_1_replica_n4] main]
[junit4] 2> 476333 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 476336 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 476336 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/conf/managed-schema
[junit4] 2> 476337 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 476338 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 476338 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1639948149833334784
[junit4] 2> 476340 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476340 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476340 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476343 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.UpdateLog Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 476345 INFO (searcherExecutor-2250-thread-1-processing-n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 c:c1 s:shard1_1 r:core_node6) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SolrCore [c1_shard1_1_replica_n4] Registered new searcher Searcher@6447ad6e[c1_shard1_1_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 476347 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/c1/terms/shard1_1 to Terms{values={core_node6=0}, version=0}
[junit4] 2> 476348 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/c1/leaders/shard1_1
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:45201/solr/c1_shard1_1_replica_n4/
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SyncStrategy https://127.0.0.1:45201/solr/c1_shard1_1_replica_n4/ has no replicas
[junit4] 2> 476353 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/c1/leaders/shard1_1/leader after winning as /collections/c1/leader_elect/shard1_1/election/72083678759485445-core_node6-n_0000000000
[junit4] 2> 476357 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:45201/solr/c1_shard1_1_replica_n4/ shard1_1
[junit4] 2> 476463 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476463 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476463 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476465 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 476467 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node6&collection.configName=conf&name=c1_shard1_1_replica_n4&action=CREATE&collection=c1&shard=shard1_1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=233
[junit4] 2> 476471 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node5, state: active, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: null
[junit4] 2> 476471 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_0, thisCore=c1_shard1_0_replica_n3, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=active, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node5, onlyIfActiveCheckResult=false, nodeProps: core_node5:{
[junit4] 2> "core":"c1_shard1_0_replica_n3",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476471 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_0, thisCore=c1_shard1_0_replica_n3, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=active, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node5, onlyIfActiveCheckResult=false, nodeProps: core_node5:{
[junit4] 2> "core":"c1_shard1_0_replica_n3",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476471 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_0, thisCore=c1_shard1_0_replica_n3, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=active, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node5, onlyIfActiveCheckResult=false, nodeProps: core_node5:{
[junit4] 2> "core":"c1_shard1_0_replica_n3",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476471 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:45201_solr&core=c1_shard1_0_replica_n3&qt=/admin/cores&coreNodeName=core_node5&action=PREPRECOVERY&checkLive=true&state=active&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 476472 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.PrepRecoveryOp Going to wait for coreNodeName: core_node6, state: active, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: null
[junit4] 2> 476472 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_1, thisCore=c1_shard1_1_replica_n4, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476473 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_1, thisCore=c1_shard1_1_replica_n4, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476473 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_1, thisCore=c1_shard1_1_replica_n4, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"down",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476567 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476567 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476567 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476568 INFO (watches-3611-thread-2) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_1, thisCore=c1_shard1_1_replica_n4, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=active, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476568 INFO (watches-3611-thread-1) [ ] o.a.s.h.a.PrepRecoveryOp In WaitForState(active): collection=c1, shard=shard1_1, thisCore=c1_shard1_1_replica_n4, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=active, localState=active, nodeName=127.0.0.1:45201_solr, coreNodeName=core_node6, onlyIfActiveCheckResult=false, nodeProps: core_node6:{
[junit4] 2> "core":"c1_shard1_1_replica_n4",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476568 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:45201_solr&core=c1_shard1_1_replica_n4&qt=/admin/cores&coreNodeName=core_node6&action=PREPRECOVERY&checkLive=true&state=active&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=96
[junit4] 2> 476569 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.SplitShardCmd Splitting shard core_node2 as part of slice shard1 of collection c1 on core_node2:{
[junit4] 2> "core":"c1_shard1_replica_n1",
[junit4] 2> "base_url":"https://127.0.0.1:45201/solr",
[junit4] 2> "node_name":"127.0.0.1:45201_solr",
[junit4] 2> "state":"active",
[junit4] 2> "type":"NRT",
[junit4] 2> "force_set_state":"false",
[junit4] 2> "leader":"true"}
[junit4] 2> 476570 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.h.a.SplitOp Invoked split action for core: c1_shard1_replica_n1
[junit4] 2> 476570 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 476571 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 476572 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 476572 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.SolrIndexSplitter SolrIndexSplitter: partitions=2 segments=0
[junit4] 2> 476572 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.SolrIndexSplitter SolrIndexSplitter:partition=0,partitionCount=2,range=80000000-ffffffff
[junit4] 2> 476572 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@655549c6 commitCommandVersion:-1
[junit4] 2> 476574 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.SolrIndexSplitter SolrIndexSplitter:partition=1,partitionCount=2,range=0-7fffffff
[junit4] 2> 476575 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@547a0ec7 commitCommandVersion:-1
[junit4] 2> 476577 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/c1/terms/shard1_0 to Terms{values={core_node5=1}, version=1}
[junit4] 2> 476578 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/c1/terms/shard1_1 to Terms{values={core_node6=1}, version=1}
[junit4] 2> 476578 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr x:c1_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=c1_shard1_replica_n1&qt=/admin/cores&action=SPLIT&targetCore=c1_shard1_0_replica_n3&targetCore=c1_shard1_1_replica_n4&wt=javabin&version=2&splitMethod=rewrite} status=0 QTime=8
[junit4] 2> 476579 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.CoreAdminOperation Applying buffered updates on core: c1_shard1_0_replica_n3
[junit4] 2> 476579 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.CoreAdminOperation Applying buffered updates on core: c1_shard1_1_replica_n4
[junit4] 2> 476579 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.h.a.CoreAdminOperation No buffered updates available. core=c1_shard1_1_replica_n4
[junit4] 2> 476579 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.h.a.CoreAdminOperation No buffered updates available. core=c1_shard1_0_replica_n3
[junit4] 2> 476580 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&name=c1_shard1_1_replica_n4&action=REQUESTAPPLYUPDATES&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 476580 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&name=c1_shard1_0_replica_n3&action=REQUESTAPPLYUPDATES&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 476581 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.SplitShardCmd Replication factor is 1 so switching shard states
[junit4] 2> 476582 INFO (OverseerThreadFactory-2235-thread-2-processing-n:127.0.0.1:45201_solr) [n:127.0.0.1:45201_solr c:c1 s:shard1 ] o.a.s.c.a.c.SplitShardCmd Successfully created all replica shards for all sub-slices [shard1_0, shard1_1]
[junit4] 2> 476584 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator Update shard state invoked for collection: c1 with message: {
[junit4] 2> "shard1":"inactive",
[junit4] 2> "collection":"c1",
[junit4] 2> "shard1_1":"active",
[junit4] 2> "operation":"updateshardstate",
[junit4] 2> "shard1_0":"active"}
[junit4] 2> 476584 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator Update shard state shard1 to inactive
[junit4] 2> 476584 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator Update shard state shard1_1 to active
[junit4] 2> 476584 INFO (OverseerStateUpdate-72083678759485445-127.0.0.1:45201_solr-n_0000000000) [n:127.0.0.1:45201_solr ] o.a.s.c.o.SliceMutator Update shard state shard1_0 to active
[junit4] 2> 476616 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1639948150124838912,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 476617 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1639948150125887488,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 476617 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@66e7604d[c1_shard1_0_replica_n3] main]
[junit4] 2> 476617 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 476617 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@63cd7101[c1_shard1_1_replica_n4] main]
[junit4] 2> 476618 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 476619 INFO (searcherExecutor-2245-thread-1-processing-n:127.0.0.1:45201_solr x:c1_shard1_0_replica_n3 c:c1 s:shard1_0 r:core_node5) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.c.SolrCore [c1_shard1_0_replica_n3] Registered new searcher Searcher@66e7604d[c1_shard1_0_replica_n3] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 476619 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_0 r:core_node5 x:c1_shard1_0_replica_n3 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_0_replica_n3] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:45201/solr/c1_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 476620 INFO (searcherExecutor-2250-thread-1-processing-n:127.0.0.1:45201_solr x:c1_shard1_1_replica_n4 c:c1 s:shard1_1 r:core_node6) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.c.SolrCore [c1_shard1_1_replica_n4] Registered new searcher Searcher@63cd7101[c1_shard1_1_replica_n4] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 476625 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=true&distrib.from=https://127.0.0.1:45201/solr/c1_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 10
[junit4] 2> 476629 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1639948150138470400,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 476630 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 476630 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1 r:core_node2 x:c1_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_replica_n1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=true&wt=javabin&version=2}{commit=} 0 44
[junit4] 2> 476634 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=SPLITSHARD&splitByPrefix=true&numSubShards=2&collection=c1&shard=shard1&wt=javabin&version=2} status=0 QTime=3120
[junit4] 2> 476636 INFO (TEST-SplitByPrefixTest.doTest-seed#[B980178A30F46BB3]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 1 expected:2
[junit4] 2> 476636 INFO (TEST-SplitByPrefixTest.doTest-seed#[B980178A30F46BB3]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 1 expected:2
[junit4] 2> 476636 INFO (TEST-SplitByPrefixTest.doTest-seed#[B980178A30F46BB3]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 1 expected:2
[junit4] 2> 476636 INFO (watches-3620-thread-1) [ ] o.a.s.c.SolrCloudTestCase active slice count: 1 expected:2
[junit4] 2> 476686 INFO (zkCallback-3609-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476686 INFO (zkCallback-3609-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476686 INFO (zkCallback-3622-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476686 INFO (zkCallback-3609-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [1])
[junit4] 2> 476687 INFO (watches-3620-thread-1) [ ] o.a.s.c.SolrCloudTestCase active slice count: 2 expected:2
[junit4] 2> 476687 INFO (watches-3620-thread-1) [ ] o.a.s.c.SolrCloudTestCase active replica count: 3 expected replica count: 3
[junit4] 2> 476704 INFO (TEST-SplitByPrefixTest.doTest-seed#[B980178A30F46BB3]) [ ] o.a.s.c.a.c.SplitByPrefixTest Unique prefixes: [prefix=19e7!,range=0-ffff, prefix=e5c!,range=30000-3ffff, prefix=43f!,range=70000-7ffff, prefix=7a6!,range=80000-8ffff, prefix=3b6!,range=110000-11ffff, prefix=13a!,range=420000-42ffff, prefix=1499!,range=4c0000-4cffff, prefix=16a4!,range=4f0000-4fffff, prefix=1252!,range=520000-52ffff, prefix=933!,range=5d0000-5dffff, prefix=a33!,range=6e0000-6effff, prefix=1161!,range=7c0000-7cffff, prefix=d35!,range=950000-95ffff, prefix=dbc!,range=b40000-b4ffff, prefix=1866!,range=ba0000-baffff, prefix=8ee!,range=c10000-c1ffff, prefix=efe!,range=e50000-e5ffff, prefix=1b1!,range=eb0000-ebffff]
[junit4] 2> 476710 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19e7!1!doc1 (1639948150221307904)]} 0 3
[junit4] 2> 476712 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[19e7!1!doc2 (1639948150225502208)]} 0 0
[junit4] 2> 476714 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[e5c!doc1 (1639948150226550784)]} 0 0
[junit4] 2> 476715 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[e5c!1!doc2 (1639948150228647936)]} 0 0
[junit4] 2> 476716 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43f!1!doc1 (1639948150229696512)]} 0 0
[junit4] 2> 476717 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[43f!doc2 (1639948150230745088)]} 0 0
[junit4] 2> 476719 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7a6!0!doc1 (1639948150232842240)]} 0 0
[junit4] 2> 476722 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7a6!0!doc2 (1639948150235987968)]} 0 0
[junit4] 2> 476723 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3b6!1!doc1 (1639948150237036544)]} 0 0
[junit4] 2> 476724 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3b6!doc2 (1639948150238085120)]} 0 0
[junit4] 2> 476726 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13a!doc1 (1639948150240182272)]} 0 0
[junit4] 2> 476727 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[13a!doc2 (1639948150241230848)]} 0 0
[junit4] 2> 476728 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1499!doc1 (1639948150242279424)]} 0 0
[junit4] 2> 476730 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1499!1!doc2 (1639948150243328000)]} 0 0
[junit4] 2> 476731 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16a4!1!doc1 (1639948150245425152)]} 0 0
[junit4] 2> 476732 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[16a4!doc2 (1639948150246473728)]} 0 0
[junit4] 2> 476733 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1252!doc1 (1639948150247522304)]} 0 0
[junit4] 2> 476738 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1252!doc2 (1639948150252765184)]} 0 0
[junit4] 2> 476739 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[933!1!doc1 (1639948150253813760)]} 0 0
[junit4] 2> 476741 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[933!0!doc2 (1639948150254862336)]} 0 0
[junit4] 2> 476742 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[a33!0!doc1 (1639948150256959488)]} 0 0
[junit4] 2> 476743 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[a33!doc2 (1639948150258008064)]} 0 0
[junit4] 2> 476744 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1161!1!doc1 (1639948150259056640)]} 0 0
[junit4] 2> 476746 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1161!0!doc2 (1639948150260105216)]} 0 0
[junit4] 2> 476747 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[d35!1!doc1 (1639948150262202368)]} 0 0
[junit4] 2> 476748 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[d35!doc2 (1639948150263250944)]} 0 0
[junit4] 2> 476749 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[dbc!0!doc1 (1639948150264299520)]} 0 0
[junit4] 2> 476750 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[dbc!1!doc2 (1639948150265348096)]} 0 0
[junit4] 2> 476752 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1866!doc1 (1639948150266396672)]} 0 0
[junit4] 2> 476753 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1866!0!doc2 (1639948150268493824)]} 0 0
[junit4] 2> 476754 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8ee!doc1 (1639948150269542400)]} 0 0
[junit4] 2> 476755 INFO (qtp700076704-8949) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8ee!doc2 (1639948150270590976)]} 0 0
[junit4] 2> 476756 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[efe!doc1 (1639948150271639552)]} 0 0
[junit4] 2> 476757 INFO (qtp700076704-8948) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[efe!doc2 (1639948150272688128)]} 0 0
[junit4] 2> 476758 INFO (qtp700076704-8950) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1b1!doc1 (1639948150273736704)]} 0 0
[junit4] 2> 476760 INFO (qtp700076704-8951) [n:127.0.0.1:45201_solr c:c1 s:shard1_1 r:core_node6 x:c1_shard1_1_replica_n4 ] o.a.s.u.p.LogUpdateProcessorFactory [c1_shard1_1_replica_n4] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1b1!0!doc2 (1639948150275833856)]} 0 0
[junit4] 2> 476763 INFO (qtp700076704-8952) [n:127.0.0.1:45201_solr c:c1 s:shard1
[...truncated too long message...]
ading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
ivy-availability-check:
[loadresource] Do not set property disallowed.ivy.jars.list as its length is 0.
-ivy-fail-disallowed-ivy-version:
ivy-fail:
ivy-fail:
ivy-configure:
[ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/lucene/top-level-ivy-settings.xml
resolve:
jar-checksums:
[mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/null1997658789
[copy] Copying 249 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/null1997658789
[delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-8.x/solr/null1997658789
check-working-copy:
[ivy:cachepath] :: resolving dependencies :: #;working@lucene1-us-west
[ivy:cachepath] confs: [default]
[ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;5.3.0.201903130848-r in public
[ivy:cachepath] found com.jcraft#jsch;0.1.54 in public
[ivy:cachepath] found com.jcraft#jzlib;1.1.1 in public
[ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public
[ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public
[ivy:cachepath] found org.bouncycastle#bcpg-jdk15on;1.60 in public
[ivy:cachepath] found org.bouncycastle#bcprov-jdk15on;1.60 in public
[ivy:cachepath] found org.bouncycastle#bcpkix-jdk15on;1.60 in public
[ivy:cachepath] found org.slf4j#slf4j-nop;1.7.2 in public
[ivy:cachepath] :: resolution report :: resolve 51ms :: artifacts dl 2ms
---------------------------------------------------------------------
| | modules || artifacts |
| conf | number| search|dwnlded|evicted|| number|dwnlded|
---------------------------------------------------------------------
| default | 9 | 0 | 0 | 0 || 9 | 0 |
---------------------------------------------------------------------
[wc-checker] Initializing working copy...
[wc-checker] Checking working copy status...
-jenkins-base:
BUILD SUCCESSFUL
Total time: 117 minutes 56 seconds
Archiving artifacts
java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726)
at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707)
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086)
Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene
at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741)
at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357)
at hudson.remoting.Channel.call(Channel.java:955)
at hudson.FilePath.act(FilePath.java:1072)
at hudson.FilePath.act(FilePath.java:1061)
at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1835)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
Caused: hudson.FilePath$TunneledInterruptedException
at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088)
at hudson.remoting.UserRequest.perform(UserRequest.java:212)
at hudson.remoting.UserRequest.perform(UserRequest.java:54)
at hudson.remoting.Request$2.run(Request.java:369)
at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:744)
Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000
at hudson.FilePath.act(FilePath.java:1074)
at hudson.FilePath.act(FilePath.java:1061)
at hudson.FilePath.validateAntFileMask(FilePath.java:2705)
at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243)
at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81)
at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20)
at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744)
at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690)
at hudson.model.Build$BuildExecution.post2(Build.java:186)
at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635)
at hudson.model.Run.execute(Run.java:1835)
at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43)
at hudson.model.ResourceController.execute(ResourceController.java:97)
at hudson.model.Executor.run(Executor.java:429)
No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error?
Recording test results
Build step 'Publish JUnit test result report' changed build result to UNSTABLE
Email was triggered for: Unstable (Test Failures)
Sending email for trigger: Unstable (Test Failures)