You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2020/02/28 10:09:51 UTC
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 2116 - Still
Unstable
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/2116/
2 tests failed.
FAILED: org.apache.solr.cloud.SyncSliceTest.test
Error Message:
expected:<5> but was:<4>
Stack Trace:
java.lang.AssertionError: expected:<5> but was:<4>
at __randomizedtesting.SeedInfo.seed([715008BB0BFD289A:F9043761A5014562]: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.cloud.SyncSliceTest.test(SyncSliceTest.java:150)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1082)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1054)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
FAILED: org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast
Error Message:
Request should fail after trying all replica nodes once
Stack Trace:
junit.framework.AssertionFailedError: Request should fail after trying all replica nodes once
at __randomizedtesting.SeedInfo.seed([715008BB0BFD289A:A28D2111ACCC41E6]:0)
at org.apache.lucene.util.LuceneTestCase.expectThrows(LuceneTestCase.java:2750)
at org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast(TestQueryingOnDownCollection.java:91)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 14273 lines...]
[junit4] Suite: org.apache.solr.cloud.TestQueryingOnDownCollection
[junit4] 2> 2692590 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/server/solr/configsets/_default/conf'
[junit4] 2> 2692590 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 2692591 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/data-dir-136-001
[junit4] 2> 2692591 WARN (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=5 numCloses=5
[junit4] 2> 2692591 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 2692592 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 2692592 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 3 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001
[junit4] 2> 2692601 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2692601 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2692602 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2692702 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:34608
[junit4] 2> 2692702 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:34608
[junit4] 2> 2692702 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:34608
[junit4] 2> 2692702 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 34608
[junit4] 2> 2692703 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692707 INFO (zkConnectionManagerCallback-7923-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692707 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692709 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692710 INFO (zkConnectionManagerCallback-7925-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692710 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692711 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692712 INFO (zkConnectionManagerCallback-7927-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692712 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2692818 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 2692821 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2692821 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2692821 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 2692822 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@6f472aec{/solr,null,AVAILABLE}
[junit4] 2> 2692822 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e8545fb{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:40687}
[junit4] 2> 2692822 INFO (jetty-launcher-7928-thread-1) [ ] o.e.j.s.Server Started @2692861ms
[junit4] 2> 2692822 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=40687}
[junit4] 2> 2692823 ERROR (jetty-launcher-7928-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2692823 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2692823 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 2692823 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2692823 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr
[junit4] 2> 2692823 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-28T07:57:41.966295Z
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 2692824 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@7c326ba0{/solr,null,AVAILABLE}
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e1448bc{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:46597}
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.e.j.s.Server Started @2692864ms
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46597}
[junit4] 2> 2692825 ERROR (jetty-launcher-7928-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr
[junit4] 2> 2692825 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-28T07:57:41.968934Z
[junit4] 2> 2692844 INFO (zkConnectionManagerCallback-7930-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692844 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5515cf9c{/solr,null,AVAILABLE}
[junit4] 2> 2692844 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@7035599d{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41561}
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-3) [ ] o.e.j.s.Server Started @2692884ms
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41561}
[junit4] 2> 2692845 ERROR (jetty-launcher-7928-thread-3) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 2692845 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 2692846 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2692846 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr
[junit4] 2> 2692846 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-02-28T07:57:41.989050Z
[junit4] 2> 2692846 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2692847 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2692847 INFO (zkConnectionManagerCallback-7932-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692847 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692847 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2692847 INFO (zkConnectionManagerCallback-7934-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2692847 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2692872 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2692976 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2692999 WARN (jetty-launcher-7928-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2a2671b5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2692999 WARN (jetty-launcher-7928-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2a2671b5[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693011 WARN (jetty-launcher-7928-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@400c1000[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693011 WARN (jetty-launcher-7928-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@400c1000[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693012 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 2693013 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693027 INFO (zkConnectionManagerCallback-7941-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693027 INFO (jetty-launcher-7928-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693076 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2693077 WARN (jetty-launcher-7928-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@71434e65[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693077 WARN (jetty-launcher-7928-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@71434e65[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693080 WARN (jetty-launcher-7928-thread-3) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5efe4804[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693080 WARN (jetty-launcher-7928-thread-3) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5efe4804[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693081 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 2693082 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693083 INFO (zkConnectionManagerCallback-7948-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693091 INFO (jetty-launcher-7928-thread-3) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693176 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 2693177 WARN (jetty-launcher-7928-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@22016095[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693177 WARN (jetty-launcher-7928-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@22016095[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693179 WARN (jetty-launcher-7928-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4495b6ef[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693179 WARN (jetty-launcher-7928-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4495b6ef[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 2693181 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:34608/solr
[junit4] 2> 2693209 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693246 INFO (zkConnectionManagerCallback-7955-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693246 INFO (jetty-launcher-7928-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693279 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693280 INFO (zkConnectionManagerCallback-7957-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693280 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693380 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693381 INFO (zkConnectionManagerCallback-7961-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693381 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693450 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:46597_solr
[junit4] 2> 2693451 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.Overseer Overseer (id=72362480442277898-127.0.0.1:46597_solr-n_0000000000) starting
[junit4] 2> 2693481 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2693494 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46597_solr
[junit4] 2> 2693495 INFO (zkConnectionManagerCallback-7965-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2693495 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2693496 INFO (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:46597_solr
[junit4] 2> 2693510 INFO (zkCallback-7960-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2693512 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2693512 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 2693549 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2693578 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:40687_solr as DOWN
[junit4] 2> 2693597 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 2693616 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2693616 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40687_solr
[junit4] 2> 2693621 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2693627 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2693627 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 2693627 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 2693632 INFO (zkCallback-7964-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2693824 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2693836 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:41561_solr as DOWN
[junit4] 2> 2693837 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2693837 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41561_solr
[junit4] 2> 2693847 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2693847 INFO (zkCallback-7956-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2693849 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 2693849 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.CoreContainer Initializing authorization plugin: solr.RuleBasedAuthorizationPlugin
[junit4] 2> 2693849 INFO (zkCallback-7964-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 2693849 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.CoreContainer Initializing authentication plugin: solr.BasicAuthPlugin
[junit4] 2> 2693898 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2693927 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2693995 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 2694124 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46597.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694129 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40687.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694185 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41561.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694195 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46597.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694195 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46597.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694198 INFO (jetty-launcher-7928-thread-2) [n:127.0.0.1:46597_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node2/.
[junit4] 2> 2694200 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40687.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694201 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_40687.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694202 INFO (jetty-launcher-7928-thread-1) [n:127.0.0.1:40687_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node1/.
[junit4] 2> 2694252 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41561.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694252 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41561.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2694270 INFO (jetty-launcher-7928-thread-3) [n:127.0.0.1:41561_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node3/.
[junit4] 2> 2694630 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=3
[junit4] 2> 2694631 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 2694632 INFO (zkConnectionManagerCallback-7978-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 2694632 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 2694633 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 2694635 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:34608/solr ready
[junit4] 2> 2694725 INFO (TEST-TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast-seed#[715008BB0BFD289A]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testQueryToDownCollectionShouldFailFast
[junit4] 2> 2694732 INFO (qtp272804227-23957) [n:127.0.0.1:40687_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf&name=infected&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2694755 INFO (OverseerThreadFactory-6554-thread-1-processing-n:127.0.0.1:46597_solr) [n:127.0.0.1:46597_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection infected
[junit4] 2> 2694864 INFO (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"infected",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"infected_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:41561/solr",
[junit4] 2> "node_name":"127.0.0.1:41561_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2694883 INFO (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":"infected",
[junit4] 2> "shard":"shard2",
[junit4] 2> "core":"infected_shard2_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46597/solr",
[junit4] 2> "node_name":"127.0.0.1:46597_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 2695090 INFO (qtp2129836083-23965) [n:127.0.0.1:41561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 2695090 INFO (qtp2129836083-23962) [n:127.0.0.1:41561_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 2695090 INFO (qtp2129836083-23969) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:41561_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 2695090 INFO (qtp282309846-23964) [ ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:41561_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 2695091 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr x:infected_shard2_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=infected_shard2_replica_n2&action=CREATE&numShards=2&collection=infected&shard=shard2&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2695091 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr x:infected_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=infected_shard1_replica_n1&action=CREATE&numShards=2&collection=infected&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 2695091 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr x:infected_shard2_replica_n2 ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 2695110 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2695133 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 2695165 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.IndexSchema [infected_shard1_replica_n1] Schema name=minimal
[junit4] 2> 2695168 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2695168 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'infected_shard1_replica_n1' using configuration from configset conf, trusted=true
[junit4] 2> 2695168 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.IndexSchema [infected_shard2_replica_n2] Schema name=minimal
[junit4] 2> 2695169 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41561.solr.core.infected.shard1.replica_n1' (registry 'solr.core.infected.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2695169 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [[infected_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node3/infected_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node3/./infected_shard1_replica_n1/data/]
[junit4] 2> 2695170 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2695171 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore 'infected_shard2_replica_n2' using configuration from configset conf, trusted=true
[junit4] 2> 2695171 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46597.solr.core.infected.shard2.replica_n2' (registry 'solr.core.infected.shard2.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5a05d5a
[junit4] 2> 2695171 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [[infected_shard2_replica_n2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node2/infected_shard2_replica_n2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001/tempDir-001/node2/./infected_shard2_replica_n2/data/]
[junit4] 2> 2695637 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2695637 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2695640 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2695640 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2695643 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@da33351[infected_shard2_replica_n2] main]
[junit4] 2> 2695657 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2695657 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2695657 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2695657 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2695658 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2695658 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659766481670373376
[junit4] 2> 2695660 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2695660 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2695662 INFO (searcherExecutor-6568-thread-1-processing-n:127.0.0.1:46597_solr x:infected_shard2_replica_n2 c:infected s:shard2 r:core_node4) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] Registered new searcher Searcher@da33351[infected_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2695674 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@4988aeef[infected_shard1_replica_n1] main]
[junit4] 2> 2695681 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard2 to Terms{values={core_node4=0}, version=0}
[junit4] 2> 2695681 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/infected/leaders/shard2
[junit4] 2> 2695682 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf
[junit4] 2> 2695683 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf
[junit4] 2> 2695683 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 2695683 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659766481696587776
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46597/solr/infected_shard2_replica_n2/
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SyncStrategy http://127.0.0.1:46597/solr/infected_shard2_replica_n2/ has no replicas
[junit4] 2> 2695686 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/infected/leaders/shard2/leader after winning as /collections/infected/leader_elect/shard2/election/72362480442277898-core_node4-n_0000000000
[junit4] 2> 2695688 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46597/solr/infected_shard2_replica_n2/ shard2
[junit4] 2> 2695699 INFO (searcherExecutor-6567-thread-1-processing-n:127.0.0.1:41561_solr x:infected_shard1_replica_n1 c:infected s:shard1 r:core_node3) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] Registered new searcher Searcher@4988aeef[infected_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2695711 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 2695711 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/infected/leaders/shard1
[junit4] 2> 2695736 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2695736 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2695736 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:41561/solr/infected_shard1_replica_n1/
[junit4] 2> 2695736 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 2695737 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:41561/solr/infected_shard1_replica_n1/ has no replicas
[junit4] 2> 2695737 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/infected/leaders/shard1/leader after winning as /collections/infected/leader_elect/shard1/election/72362480442277897-core_node3-n_0000000000
[junit4] 2> 2695748 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:41561/solr/infected_shard1_replica_n1/ shard1
[junit4] 2> 2695850 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695850 INFO (zkCallback-7960-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695850 INFO (zkCallback-7956-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695850 INFO (zkCallback-7956-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695851 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2695853 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=conf&newCollection=true&name=infected_shard2_replica_n2&action=CREATE&numShards=2&collection=infected&shard=shard2&wt=javabin&version=2&replicaType=NRT} status=0 QTime=762
[junit4] 2> 2695867 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2695870 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&newCollection=true&name=infected_shard1_replica_n1&action=CREATE&numShards=2&collection=infected&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=779
[junit4] 2> 2695872 INFO (qtp272804227-23957) [n:127.0.0.1:40687_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> 2695970 INFO (zkCallback-7960-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7964-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7956-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7960-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7956-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695970 INFO (zkCallback-7956-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2695971 INFO (qtp272804227-23957) [n:127.0.0.1:40687_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf&name=infected&nrtReplicas=1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=1239
[junit4] 2> 2695990 INFO (qtp2129836083-23965) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard1 to Terms{values={core_node3=1}, version=1}
[junit4] 2> 2695990 INFO (qtp2129836083-23965) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=infected:4&wt=javabin&version=2}{add=[0 (1659766482004869120), 1 (1659766482006966272), 4 (1659766482006966273), 8 (1659766482006966274), 10 (1659766482006966275), 11 (1659766482006966276), 12 (1659766482006966277), 13 (1659766482006966278), 14 (1659766482006966279), 15 (1659766482006966280), ... (56 adds)]} 0 15
[junit4] 2> 2696002 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/infected/terms/shard2 to Terms{values={core_node4=1}, version=1}
[junit4] 2> 2696003 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard2_replica_n2] webapp=/solr path=/update params={_stateVer_=infected:4&wt=javabin&version=2}{add=[2 (1659766482004869120), 3 (1659766482006966272), 5 (1659766482006966273), 6 (1659766482006966274), 7 (1659766482006966275), 9 (1659766482006966276), 17 (1659766482006966277), 18 (1659766482006966278), 19 (1659766482006966279), 21 (1659766482006966280), ... (44 adds)]} 0 27
[junit4] 2> 2696009 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659766482038423552,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2696009 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@75a861d5 commitCommandVersion:1659766482038423552
[junit4] 2> 2696030 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6d1465ad[infected_shard2_replica_n2] main]
[junit4] 2> 2696030 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2696033 INFO (searcherExecutor-6568-thread-1-processing-n:127.0.0.1:46597_solr x:infected_shard2_replica_n2 c:infected s:shard2 r:core_node4) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] Registered new searcher Searcher@6d1465ad[infected_shard2_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C44:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1582876665154}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2696033 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard2_replica_n2] webapp=/solr path=/update params={update.distrib=TOLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:41561/solr/infected_shard1_replica_n1/&commit_end_point=leaders&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 24
[junit4] 2> 2696034 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659766482064637952,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2696034 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@1cd19e0e commitCommandVersion:1659766482064637952
[junit4] 2> 2696088 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@12d9e985[infected_shard1_replica_n1] main]
[junit4] 2> 2696089 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2696091 INFO (searcherExecutor-6567-thread-1-processing-n:127.0.0.1:41561_solr x:infected_shard1_replica_n1 c:infected s:shard1 r:core_node3) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] Registered new searcher Searcher@12d9e985[infected_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C56:[diagnostics={java.version=11.0.4, java.vm.version=11.0.4+10-LTS, lucene.version=9.0.0, source=flush, os.arch=amd64, java.runtime.version=11.0.4+10-LTS, os.version=4.4.0-170-generic, os=Linux, java.vendor=Oracle Corporation, timestamp=1582876665179}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 2696091 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [infected_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=infected:4&commit=true&wt=javabin&version=2}{commit=} 0 87
[junit4] 2> 2696093 INFO (zkCallback-7956-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696093 INFO (zkCallback-7956-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696093 INFO (zkCallback-7956-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696111 INFO (zkCallback-7960-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696111 INFO (zkCallback-7960-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696111 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/infected/state.json] for collection [infected] has occurred - updating... (live nodes size: [3])
[junit4] 2> 2696111 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 2696111 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:46597_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 2696112 INFO (qtp2129836083-23969) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.S.Request [infected_shard1_replica_n1] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=http://127.0.0.1:41561/solr/infected_shard1_replica_n1/&rows=0&_forwardedCount=1&version=2&q=*:*&omitHeader=false&NOW=1582876665249&isShard=true&wt=javabin} hits=56 status=0 QTime=0
[junit4] 2> 2696123 INFO (qtp282309846-23964) [n:127.0.0.1:46597_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/key params={omitHeader=true&wt=json} status=0 QTime=0
[junit4] 2> 2696124 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.s.PKIAuthenticationPlugin New Key obtained from node: 127.0.0.1:46597_solr / MFwwDQYJKoZIhvcNAQEBBQADSwAwSAJBAMgmSVfl+E2Nj/oKAP2TceWh17pk6Ugsw5A5nLH+OeMB/WeWJZg/NEDda8SXfQDEVRmw5P+2IZypPASzfCrc6yECAwEAAQ==
[junit4] 2> 2696124 INFO (qtp282309846-23963) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.S.Request [infected_shard2_replica_n2] webapp=/solr path=/select params={df=text&distrib=false&fl=id&fl=score&shards.purpose=16388&start=0&fsv=true&shard.url=http://127.0.0.1:46597/solr/infected_shard2_replica_n2/&rows=0&_forwardedCount=1&version=2&q=*:*&omitHeader=false&NOW=1582876665249&isShard=true&wt=javabin} hits=44 status=0 QTime=0
[junit4] 2> 2696125 INFO (qtp282309846-23966) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.S.Request [infected_shard2_replica_n2] webapp=/solr path=/select params={q=*:*&rows=0&_forwardedCount=1&wt=javabin&version=2} hits=100 status=0 QTime=18
[junit4] 2> 2696127 INFO (TEST-TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast-seed#[715008BB0BFD289A]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testQueryToDownCollectionShouldFailFast
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestQueryingOnDownCollection -Dtests.method=testQueryToDownCollectionShouldFailFast -Dtests.seed=715008BB0BFD289A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=en-SZ -Dtests.timezone=Asia/Seoul -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 1.48s J0 | TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast <<<
[junit4] > Throwable #1: junit.framework.AssertionFailedError: Request should fail after trying all replica nodes once
[junit4] > at __randomizedtesting.SeedInfo.seed([715008BB0BFD289A:A28D2111ACCC41E6]:0)
[junit4] > at org.apache.lucene.util.LuceneTestCase.expectThrows(LuceneTestCase.java:2750)
[junit4] > at org.apache.solr.cloud.TestQueryingOnDownCollection.testQueryToDownCollectionShouldFailFast(TestQueryingOnDownCollection.java:91)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> 2696230 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=7869419
[junit4] 2> 2696230 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=870361665
[junit4] 2> 2696230 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:40687_solr
[junit4] 2> 2696230 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:41561_solr
[junit4] 2> 2696231 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2696231 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2696231 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:40687_solr as DOWN
[junit4] 2> 2696231 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:41561_solr as DOWN
[junit4] 2> 2696243 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=48014164
[junit4] 2> 2696243 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.c.ZkController Remove node as live in ZooKeeper:/live_nodes/127.0.0.1:46597_solr
[junit4] 2> 2696244 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.c.ZkController Publish this node as DOWN...
[junit4] 2> 2696244 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.c.ZkController Publish node=127.0.0.1:46597_solr as DOWN
[junit4] 2> 2696277 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2696281 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1f20a082: rootName = solr_40687, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@673abbdf
[junit4] 2> 2696310 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2696310 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5111c3d: rootName = solr_40687, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7eafb1d
[junit4] 2> 2696326 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2696326 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@2098eb2f: rootName = solr_40687, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2085b7be
[junit4] 2> 2696326 INFO (jetty-closer-7981-thread-1) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2696330 INFO (coreCloseExecutor-6578-thread-1) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.c.SolrCore [infected_shard1_replica_n1] CLOSING SolrCore org.apache.solr.core.SolrCore@539de13b
[junit4] 2> 2696330 INFO (coreCloseExecutor-6578-thread-1) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.infected.shard1.replica_n1, tag=SolrCore@539de13b
[junit4] 2> 2696330 INFO (coreCloseExecutor-6578-thread-1) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@49c2aacd: rootName = solr_41561, domain = solr.core.infected.shard1.replica_n1, service url = null, agent id = null] for registry solr.core.infected.shard1.replica_n1 / com.codahale.metrics.MetricRegistry@570215c
[junit4] 2> 2696331 INFO (coreCloseExecutor-6579-thread-1) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.c.SolrCore [infected_shard2_replica_n2] CLOSING SolrCore org.apache.solr.core.SolrCore@46c4a27f
[junit4] 2> 2696331 INFO (coreCloseExecutor-6579-thread-1) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.infected.shard2.replica_n2, tag=SolrCore@46c4a27f
[junit4] 2> 2696331 INFO (zkCallback-7956-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 2696331 INFO (coreCloseExecutor-6579-thread-1) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@1c143579: rootName = solr_46597, domain = solr.core.infected.shard2.replica_n2, service url = null, agent id = null] for registry solr.core.infected.shard2.replica_n2 / com.codahale.metrics.MetricRegistry@3c1dc07e
[junit4] 2> 2696388 INFO (coreCloseExecutor-6578-thread-1) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.infected.shard1.leader, tag=SolrCore@539de13b
[junit4] 2> 2696389 INFO (coreCloseExecutor-6579-thread-1) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.collection.infected.shard2.leader, tag=SolrCore@46c4a27f
[junit4] 2> 2696389 INFO (coreCloseExecutor-6578-thread-1) [n:127.0.0.1:41561_solr c:infected s:shard1 r:core_node3 x:infected_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 2696390 INFO (coreCloseExecutor-6579-thread-1) [n:127.0.0.1:46597_solr c:infected s:shard2 r:core_node4 x:infected_shard2_replica_n2 ] o.a.s.u.DirectUpdateHandler2 Committing on IndexWriter.close() ... SKIPPED (unnecessary).
[junit4] 2> 2696404 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2696415 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@15f6b8d9: rootName = solr_41561, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@34085701
[junit4] 2> 2696415 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null
[junit4] 2> 2696415 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@5bb93219: rootName = solr_46597, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@718f4b00
[junit4] 2> 2696441 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2696441 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@57788195: rootName = solr_41561, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7eafb1d
[junit4] 2> 2696445 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null
[junit4] 2> 2696445 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@312179a: rootName = solr_46597, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@7eafb1d
[junit4] 2> 2696460 INFO (zkCallback-7960-thread-2) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (2)
[junit4] 2> 2696461 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2696461 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@54280e60: rootName = solr_41561, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2085b7be
[junit4] 2> 2696461 INFO (jetty-closer-7981-thread-2) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2696465 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null
[junit4] 2> 2696465 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@32ba3ce9: rootName = solr_46597, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@2085b7be
[junit4] 2> 2696466 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.cluster, tag=null
[junit4] 2> 2696468 ERROR (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.Overseer Exception in Overseer main queue loop
[junit4] 2> => org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /collections/infected/state.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:122)
[junit4] 2> org.apache.zookeeper.KeeperException$BadVersionException: KeeperErrorCode = BadVersion for /collections/infected/state.json
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:122) ~[zookeeper-3.5.5.jar:3.5.5]
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:54) ~[zookeeper-3.5.5.jar:3.5.5]
[junit4] 2> at org.apache.zookeeper.ZooKeeper.setData(ZooKeeper.java:2384) ~[zookeeper-3.5.5.jar:3.5.5]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.lambda$setData$6(SolrZkClient.java:350) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:71) ~[java/:?]
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.setData(SolrZkClient.java:350) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.overseer.ZkStateWriter.writePendingUpdates(ZkStateWriter.java:199) ~[java/:?]
[junit4] 2> at org.apache.solr.cloud.Overseer$ClusterStateUpdater.run(Overseer.java:259) ~[java/:?]
[junit4] 2> at java.lang.Thread.run(Thread.java:834) [?:?]
[junit4] 2> 2696480 INFO (closeThreadPool-7993-thread-2) [ ] o.a.s.c.Overseer Overseer (id=72362480442277898-127.0.0.1:46597_solr-n_0000000000) closing
[junit4] 2> 2696480 INFO (OverseerAutoScalingTriggerThread-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 2696480 INFO (jetty-closer-7981-thread-1) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1e8545fb{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 2696488 INFO (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.Overseer According to ZK I (id=72362480442277898-127.0.0.1:46597_solr-n_0000000000) am no longer a leader. propsId=null
[junit4] 2> 2696488 INFO (OverseerStateUpdate-72362480442277898-127.0.0.1:46597_solr-n_0000000000) [n:127.0.0.1:46597_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:46597_solr
[junit4] 2> 2696531 INFO (jetty-closer-7981-thread-1) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6f472aec{/solr,null,UNAVAILABLE}
[junit4] 2> 2696533 INFO (jetty-closer-7981-thread-1) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2696534 INFO (closeThreadPool-7993-thread-1) [ ] o.a.s.c.Overseer Overseer (id=72362480442277898-127.0.0.1:46597_solr-n_0000000000) closing
[junit4] 2> 2696586 INFO (jetty-closer-7981-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@7035599d{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 2696586 INFO (jetty-closer-7981-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@5515cf9c{/solr,null,UNAVAILABLE}
[junit4] 2> 2696586 INFO (jetty-closer-7981-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2696691 INFO (jetty-closer-7981-thread-3) [ ] o.a.s.c.Overseer Overseer (id=72362480442277898-127.0.0.1:46597_solr-n_0000000000) closing
[junit4] 2> 2696692 INFO (jetty-closer-7981-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1e1448bc{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:0}
[junit4] 2> 2696693 INFO (jetty-closer-7981-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@7c326ba0{/solr,null,UNAVAILABLE}
[junit4] 2> 2696693 INFO (jetty-closer-7981-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 2696693 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 2696918 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 4 /solr/aliases.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 3 /solr/packages.json
[junit4] 2> 3 /solr/collections/infected/terms/shard2
[junit4] 2> 3 /solr/collections/infected/terms/shard1
[junit4] 2> 3 /solr/security.json
[junit4] 2> 2 /solr/configs/conf
[junit4] 2> 2 /solr/collections/infected/collectionprops.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 26 /solr/collections/infected/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 2 /solr/overseer_elect/election/72362480442277898-127.0.0.1:46597_solr-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 19 /solr/overseer/queue
[junit4] 2> 12 /solr/live_nodes
[junit4] 2> 8 /solr/collections
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2>
[junit4] 2> 2696920 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:34608
[junit4] 2> 2696920 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:34608
[junit4] 2> 2696920 INFO (SUITE-TestQueryingOnDownCollection-seed#[715008BB0BFD289A]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 34608
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.TestQueryingOnDownCollection_715008BB0BFD289A-001
[junit4] 2> Feb 28, 2020 7:57:46 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@1e2c9501), locale=en-SZ, timezone=Asia/Seoul
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=270453752,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [NotRequiredUniqueKeyTest, FacetPivotSmallTest, RoutingToNodesWithPropertiesTest, PKIAuthenticationIntegrationTest, TestCloudConsistency, StatsReloadRaceTest, DistributedFacetSimpleRefinementLongTailTest, TestExactStatsCache, LegacyCloudClusterPropTest, SpellCheckComponentTest, SystemCollectionCompatTest, NodeAddedTriggerIntegrationTest, PolyFieldTest, TestTextField, TestSizeLimitedDistributedMap, TestLocalFSCloudBackupRestore, SampleTest, ComputePlanActionTest, TestConfigSetsAPIZkFailure, TestSolrJ, SubstringBytesRefFilterTest, OverseerTest, TestZkChroot, TestMissingGroups, TestReqParamsAPI, TestReRankQParserPlugin, DistributedSpellCheckComponentTest, TestSuggestSpellingConverter, TestNestedDocsSort, CollectionsAPIAsyncDistributedZkTest, TestCollectionAPI, TestBinaryResponseWriter, BJQParserTest, SolrIndexSplitterTest, ShowFileRequestHandlerTest, TestSolrCachePerf, UUIDFieldTest, PrimUtilsTest, CloudMLTQParserTest, ActionThrottleTest, BlobRepositoryCloudTest, TestEmbeddedSolrServerSchemaAPI, TestCollectionAPIs, DateRangeFieldTest, TestGeoJSONResponseWriter, ParsingFieldUpdateProcessorsTest, SuggestComponentTest, SolrJmxReporterCloudTest, TestRTGBase, DistributedQueryComponentCustomSortTest, DistributedFacetPivotSmallTest, CustomHighlightComponentTest, TestSchemaResource, BigEndianAscendingWordSerializerTest, PhrasesIdentificationComponentTest, TestIBSimilarityFactory, SolrCoreCheckLockOnStartupTest, TestZkAclsWithHadoopAuth, OutOfBoxZkACLAndCredentialsProvidersTest, SpatialRPTFieldTypeTest, TestIntervalFaceting, CoreAdminHandlerTest, TestLegacyFieldCache, MoveReplicaHDFSTest, TestDistributedTracing, XMLAtomicUpdateMultivalueTest, SpellCheckCollatorWithCollapseTest, HttpSolrCallGetCoreTest, CdcrReplicationHandlerTest, TestImplicitCoreProperties, DocumentAnalysisRequestHandlerTest, ChaosMonkeySafeLeaderTest, TestUninvertingReader, TestSchemaManager, TestBadConfig, Sor
[...truncated too long message...]
"BEFORE_ACTION",
[junit4] 1> "AFTER_ACTION",
[junit4] 1> "IGNORED"],
[junit4] 1> "trigger":".scheduled_maintenance",
[junit4] 1> "class":"org.apache.solr.cloud.autoscaling.SystemLogListener"}},
[junit4] 1> "properties":{}}
[junit4] 1> /solr/clusterprops.json (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "legacyCloud":"true",
[junit4] 1> "urlScheme":"https"}
[junit4] 1>
[junit4] 2> 3939658 INFO (TEST-SyncSliceTest.test-seed#[715008BB0BFD289A]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 3939877 WARN (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Watch limit violations:
[junit4] 2> Maximum concurrent create/delete watches above limit:
[junit4] 2>
[junit4] 2> 42 /solr/collections/collection1/terms/shard1
[junit4] 2> 28 /solr/collections/collection1/state.json
[junit4] 2> 10 /solr/aliases.json
[junit4] 2> 8 /solr/packages.json
[junit4] 2> 8 /solr/security.json
[junit4] 2> 8 /solr/configs/conf1
[junit4] 2> 7 /solr/collections/collection1/collectionprops.json
[junit4] 2> 3 /solr/collections/control_collection/terms/shard1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 233 /solr/clusterstate.json
[junit4] 2> 12 /solr/collections/control_collection/state.json
[junit4] 2> 10 /solr/clusterprops.json
[junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/72362557650829338-core_node8-n_0000000003
[junit4] 2> 2 /solr/overseer_elect/election/72362557650829317-127.0.0.1:41384_gdzt%2Fz-n_0000000000
[junit4] 2> 2 /solr/collections/collection1/leader_elect/shard1/election/72362557650829326-core_node4-n_0000000001
[junit4] 2> 2 /solr/overseer_elect/election/72362557650829326-127.0.0.1:39902_gdzt%2Fz-n_0000000002
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 76 /solr/overseer/queue
[junit4] 2> 74 /solr/live_nodes
[junit4] 2> 25 /solr/overseer/collection-queue-work
[junit4] 2> 10 /solr/collections
[junit4] 2>
[junit4] 2> 3939879 INFO (TEST-SyncSliceTest.test-seed#[715008BB0BFD289A]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:45014
[junit4] 2> 3939879 INFO (TEST-SyncSliceTest.test-seed#[715008BB0BFD289A]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:45014
[junit4] 2> 3939879 INFO (TEST-SyncSliceTest.test-seed#[715008BB0BFD289A]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 45014
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=test -Dtests.seed=715008BB0BFD289A -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=cgg -Dtests.timezone=America/Fort_Nelson -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 69.2s J2 | SyncSliceTest.test <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<5> but was:<4>
[junit4] > at __randomizedtesting.SeedInfo.seed([715008BB0BFD289A:F9043761A5014562]:0)
[junit4] > at org.apache.solr.cloud.SyncSliceTest.test(SyncSliceTest.java:150)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1082)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1054)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J2/temp/solr.cloud.SyncSliceTest_715008BB0BFD289A-001
[junit4] 2> Feb 28, 2020 8:18:29 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@2330820), locale=cgg, timezone=America/Fort_Nelson
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=355285056,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestCoreAdminApis, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestSolrQueryResponse, AlternateDirectoryTest, DistributedTermsComponentTest, SmileWriterTest, CreateCollectionCleanupTest, SystemLogListenerTest, TestConfigSetsAPIExclusivity, TestSolrConfigHandlerConcurrent, TestTolerantUpdateProcessorRandomCloud, ShardsWhitelistTest, HdfsWriteToMultipleCollectionsTest, TestDocTermOrdsUninvertLimit, AnalyticsQueryTest, TestDynamicURP, TestRequestStatusCollectionAPI, ExplicitHLLTest, TestSolrCLIRunExample, UninvertDocValuesMergePolicyTest, TestTrieFacet, TestJsonFacetsWithNestedObjects, SolrGraphiteReporterTest, TestCustomDocTransformer, CoreAdminCreateDiscoverTest, TestSortableTextField, TestHdfsCloudBackupRestore, TestFieldCacheSort, CoreSorterTest, MetricUtilsTest, SolrRrdBackendFactoryTest, BadCopyFieldTest, TestMinHashQParser, TestSchemaVersionResource, TestEmbeddedSolrServerConstructors, TestFuzzyAnalyzedSuggestions, TestWithCollection, TestRangeQuery, ByteBuffersDirectoryFactoryTest, CloudReplicaSourceTest, MetricsHistoryWithAuthIntegrationTest, TestElisionMultitermQuery, OrderedExecutorTest, TestDFRSimilarityFactory, TestCloudInspectUtil, TestQueryUtils, TestDistributedGrouping, DistribDocExpirationUpdateProcessorTest, PeerSyncWithLeaderAndIndexFingerprintCachingTest, FastVectorHighlighterTest, DocValuesMultiTest, DebugComponentTest, TestConfig, DistributedQueryElevationComponentTest, SaslZkACLProviderTest, MultiSolrCloudTestCaseTest, TestSort, SignatureUpdateProcessorFactoryTest, IndexSizeEstimatorTest, OverseerCollectionConfigSetProcessorTest, AtomicUpdateRemovalJavabinTest, BasicAuthOnSingleNodeTest, TestLocalStatsCacheCloud, ClusterStateMockUtilTest, NodeMutatorTest, TestFaceting, SimpleFacetsTest, SoftAutoCommitTest, OverseerTaskQueueTest, EmbeddedSolrNoSerializeTest, TestJoin, TestFilteredDocIdSet, ManagedSchemaRoundRobinCloudTest, ZkCLITest, TestPerFieldSimilarity, DistributedFacetPivotSmallAdvancedTest, TestSha256AuthenticationProvider, TestSolr4Spatial2, SharedFSAutoReplicaFailoverTest, FuzzySearchTest, BaseCdcrDistributedZkTest, TestBackupRepositoryFactory, TestRequestForwarding, SpatialHeatmapFacetsTest, TestSolrFieldCacheBean, DeleteShardTest, TestSchemaNameResource, TestJsonRequest, DistanceUnitsTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, TestDeleteCollectionOnDownNodes, SuggesterWFSTTest, SolrCloudExampleTest, TestSolrDeletionPolicy2, URLClassifyProcessorTest, ResolveAnalyzerByNameTest, DirectUpdateHandlerTest, XsltUpdateRequestHandlerTest, TestInPlaceUpdatesDistrib, TestTolerantSearch, TestDocumentBuilder, JvmMetricsTest, TestFieldCacheWithThreads, TriggerEventQueueTest, TestJavabinTupleStreamParser, TestXIncludeConfig, TestPayloadScoreQParserPlugin, LeaderVoteWaitTimeoutTest, SegmentsInfoRequestHandlerTest, HdfsRecoveryZkTest, TestMinMaxOnMultiValuedField, TaggerTest, TokenizerChainTest, TestLegacyTerms, TestBinaryField, HdfsDirectoryTest, MetricTriggerTest, ResponseBuilderTest, CollectionPropsTest, TriLevelCompositeIdRoutingTest, QueryEqualityTest, TestRestManager, TestExplainDocTransformer, PeerSyncTest, TestMergePolicyConfig, CSVRequestHandlerTest, MoveReplicaHDFSFailoverTest, HdfsDirectoryFactoryTest, TransactionLogTest, IndexSizeTriggerSizeEstimationTest, TestCollapseQParserPlugin, TestManagedStopFilterFactory, TestDynamicFieldCollectionResource, ProtectedTermFilterFactoryTest, CdcrOpsAndBoundariesTest, DirectSolrSpellCheckerTest, TestSimGenericDistributedQueue, SpatialFilterTest, TestSimClusterStateProvider, TestUnifiedSolrHighlighter, CircularListTest, TestRawResponseWriter, MultiDestinationAuditLoggerTest, ZkNodePropsTest, TestDownShardTolerantSearch, CloneFieldUpdateProcessorFactoryTest, ConcurrentCreateRoutedAliasTest, ConvertedLegacyTest, CursorPagingTest, DisMaxRequestHandlerTest, DistributedIntervalFacetingTest, EchoParamsTest, MinimalSchemaTest, OutputWriterTest, SolrTestCaseJ4Test, TestGroupingSearch, TestHighlightDedupGrouping, TestSimpleTrackingShardHandler, TestSolrCoreProperties, TestSolrTestCaseJ4, TestTrie, PathHierarchyTokenizerFactoryTest, TestCharFilters, TestDeprecatedFilters, TestLuceneMatchVersion, ConnectionReuseTest, AliasIntegrationTest, AssignBackwardCompatibilityTest, BasicDistributedZk2Test, ClusterStateTest, ClusterStateUpdateTest, CollectionStateFormat2Test, CollectionsAPISolrJTest, DeleteInactiveReplicaTest, DistribCursorPagingTest, ForceLeaderWithTlogReplicasTest, HealthCheckHandlerTest, HttpPartitionOnCommitTest, LeaderElectionTest, LeaderFailureAfterFreshStartTest, RecoveryAfterSoftCommitTest, RecoveryZkTest, ReindexCollectionTest, RestartWhileUpdatingTest, SliceStateTest, SolrCLIZkUtilsTest, SolrXmlInZkTest, SplitShardTest, SyncSliceTest]
[junit4] Completed [518/905 (2!)] on J2 in 69.70s, 1 test, 1 failure <<< FAILURES!
[...truncated 53974 lines...]
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 2119 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/2119/
2 tests failed.
FAILED: org.apache.lucene.analysis.core.TestRandomChains.testRandomChainsWithLargeStrings
Error Message:
For input string: "ꡗ 檓젏 쀖 cpbtmd nhnbpm"
Stack Trace:
java.lang.NumberFormatException: For input string: "ꡗ 檓젏
쀖 cpbtmd nhnbpm"
at __randomizedtesting.SeedInfo.seed([2491B86F805356D3:4ECA077ED91D7620]:0)
at java.base/jdk.internal.math.FloatingDecimal.readJavaFormatString(FloatingDecimal.java:2054)
at java.base/jdk.internal.math.FloatingDecimal.parseFloat(FloatingDecimal.java:122)
at java.base/java.lang.Float.parseFloat(Float.java:455)
at org.apache.lucene.analysis.boost.DelimitedBoostTokenFilter.incrementToken(DelimitedBoostTokenFilter.java:52)
at org.apache.lucene.analysis.miscellaneous.ConditionalTokenFilter.incrementToken(ConditionalTokenFilter.java:186)
at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
at org.apache.lucene.analysis.gl.GalicianMinimalStemFilter.incrementToken(GalicianMinimalStemFilter.java:48)
at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
at org.apache.lucene.analysis.miscellaneous.ConditionalTokenFilter.incrementToken(ConditionalTokenFilter.java:174)
at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
at org.apache.lucene.analysis.hu.HungarianLightStemFilter.incrementToken(HungarianLightStemFilter.java:48)
at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkAnalysisConsistency(BaseTokenStreamTestCase.java:716)
at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkRandomData(BaseTokenStreamTestCase.java:630)
at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkRandomData(BaseTokenStreamTestCase.java:558)
at org.apache.lucene.analysis.core.TestRandomChains.testRandomChainsWithLargeStrings(TestRandomChains.java:899)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
FAILED: org.apache.lucene.search.TestXYPointDistanceSort.testRandomHuge
Error Message:
expected:<Result [id=87, distance=5.452996303315124E37]> but was:<Result [id=147, distance=5.452996303315124E37]>
Stack Trace:
java.lang.AssertionError: expected:<Result [id=87, distance=5.452996303315124E37]> but was:<Result [id=147, distance=5.452996303315124E37]>
at __randomizedtesting.SeedInfo.seed([DF0A7DE3D1222E59:1C4B45F7C0AA677C]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotEquals(Assert.java:834)
at org.junit.Assert.assertEquals(Assert.java:118)
at org.junit.Assert.assertEquals(Assert.java:144)
at org.apache.lucene.search.TestXYPointDistanceSort.doRandomTest(TestXYPointDistanceSort.java:247)
at org.apache.lucene.search.TestXYPointDistanceSort.testRandomHuge(TestXYPointDistanceSort.java:136)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 2068 lines...]
[junit4] Suite: org.apache.lucene.search.TestXYPointDistanceSort
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestXYPointDistanceSort -Dtests.method=testRandomHuge -Dtests.seed=DF0A7DE3D1222E59 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=ka -Dtests.timezone=Atlantic/Reykjavik -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] FAILURE 6.70s J1 | TestXYPointDistanceSort.testRandomHuge <<<
[junit4] > Throwable #1: java.lang.AssertionError: expected:<Result [id=87, distance=5.452996303315124E37]> but was:<Result [id=147, distance=5.452996303315124E37]>
[junit4] > at __randomizedtesting.SeedInfo.seed([DF0A7DE3D1222E59:1C4B45F7C0AA677C]:0)
[junit4] > at org.apache.lucene.search.TestXYPointDistanceSort.doRandomTest(TestXYPointDistanceSort.java:247)
[junit4] > at org.apache.lucene.search.TestXYPointDistanceSort.testRandomHuge(TestXYPointDistanceSort.java:136)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/core/test/J1/temp/lucene.search.TestXYPointDistanceSort_DF0A7DE3D1222E59-001
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@10636dbe), locale=ka, timezone=Atlantic/Reykjavik
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=353817416,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestPrefixRandom, TestCodecUtil, TestFilterSpans, TestBasicModelIn, TestMutableValues, TestNativeFSLockFactory, TestExitableDirectoryReader, TestNRTReaderCleanup, TestTopFieldCollector, TestIndexWriterNRTIsCurrent, TestRoaringDocIdSet, TestClassicSimilarity, TestSimilarityBase, TestLongsRef, TestDaciukMihovAutomatonBuilder, TestTermVectorsWriter, TestDisjunctionScoreBlockBoundaryPropagator, TestBagOfPositions, TestAddIndexes, TestXYPoint, TestLongDistanceFeatureQuery, TestIndexWriterDeleteByQuery, TestDocumentWriter, TestFixedBitDocIdSet, TestPersistentSnapshotDeletionPolicy, TestDocValuesRewriteMethod, TestMultiMMap, TestFSTs, TestTermQuery, TestStressIndexing, TestSloppyPhraseQuery2, TestNormsFieldExistsQuery, TestPositiveScoresOnlyCollector, TestLatLonPointQueries, TestFieldValueQuery, TestLatLonMultiPointShapeQueries, TestMatchesIterator, TestParallelTermEnum, TestFastLZ4, TestBoostQuery, Test2BPostings, TestIntRangeFieldQueries, TestUniqueTermCount, TestParallelCompositeReader, TestDocInverterPerFieldErrorInfo, TestFilterMergePolicy, TestLogMergePolicy, TestFastDecompressionMode, TestSpanCollection, TestRollingUpdates, TestSegmentTermEnum, TestTermStates, TestPerFieldPostingsFormat2, TestCharFilter, TestPoint, TestVirtualMethod, TestSortedSetDocValues, TestIntSet, TestSortedSetSortField, TestLatLonDocValuesField, TestIntsRef, TestCollectionUtil, LimitedFiniteStringsIteratorTest, TestSimilarityProvider, TestSimpleExplanationsWithFillerDocs, TestCustomSearcherSort, TestCustomNorms, TestByteArrayDataInput, TestMultiPhraseEnum, TestMultiFields, TestTimSorterWorstCase, TestSegmentMerger, TestXYMultiLineShapeQueries, TestReaderPool, TestFilterCodecReader, TestRangeFieldsDocValuesQuery, TestStopFilter, TestDoc, TestTimeLimitingCollector, TestForTooMuchCloning, TestLatLonPointDistanceFeatureQuery, TestCachingTokenFilter, TestFieldType, TestXYRectangle2D, TestGraphTokenFilter, TestDemo, TestFilterDirectory, TestMergedIterator, TestPackedInts, TestAxiomaticF3EXP, Test2BNumericDocValues, TestCodecHoldsOpenFiles, TestBinaryTerms, TestLatLonPointShapeQueries, TestLatLonPolygonShapeQueries, TestCodecs, TestConcurrentMergeScheduler, TestConsistentFieldNumbers, TestCrash, TestCustomTermFreq, TestDeletionPolicy, TestDemoParallelLeafReader, TestIndexWriterWithThreads, TestIndexableField, TestInfoStream, TestIntBlockPool, TestIsCurrent, TestLongPostings, TestManyFields, TestMaxPosition, TestMergeRateLimiter, TestMixedCodecs, TestMixedDocValuesUpdates, TestOmitNorms, TestOmitPositions, TestOmitTf, TestParallelLeafReader, TestPayloads, TestPayloadsOnVectors, TestPendingDeletes, TestPendingSoftDeletes, TestPostingsOffsets, TestPrefixCodedTerms, TestReadOnlyIndex, TestReaderWrapperDVTypeCheck, TestSameTokenSamePosition, TestSegmentReader, TestSizeBoundedForceMerge, TestSnapshotDeletionPolicy, TestStressIndexing2, TestStressNRT, TestSumDocFreq, TestTerms, TestTermsEnum, TestFuzzyQuery, TestIndexOrDocValuesQuery, TestLiveFieldValues, TestLongRangeFieldQueries, TestXYPointDistanceSort]
[junit4] Completed [486/563 (1!)] on J1 in 7.69s, 4 tests, 1 failure <<< FAILURES!
[...truncated 2091 lines...]
[junit4] Suite: org.apache.lucene.analysis.core.TestRandomChains
[junit4] 2> TEST FAIL: useCharFilter=false text='\ua845\ua849\ua84b\ua879\ua857\ua87a \u6a93\uc80f\uda41\udcec\r\uc016\ued9c cpbtmd nhnbpm'
[junit4] 2> Exception from random analyzer:
[junit4] 2> charfilters=
[junit4] 2> org.apache.lucene.analysis.charfilter.HTMLStripCharFilter(java.io.StringReader@64279e82, [<ALPHANUM>, <NUM>])
[junit4] 2> org.apache.lucene.analysis.fa.PersianCharFilter(org.apache.lucene.analysis.charfilter.HTMLStripCharFilter@486c09b6)
[junit4] 2> tokenizer=
[junit4] 2> org.apache.lucene.analysis.pattern.PatternTokenizer(org.apache.lucene.util.AttributeFactory$DefaultAttributeFactory@5227ae37, a, -30)
[junit4] 2> filters=
[junit4] 2> Conditional:org.apache.lucene.analysis.boost.DelimitedBoostTokenFilter(OneTimeWrapper@10097a33 term=,bytes=[],startOffset=0,endOffset=0,positionIncrement=1,boost=1.0, ꡋ)
[junit4] 2> org.apache.lucene.analysis.gl.GalicianMinimalStemFilter(ValidatingTokenFilter@269dcb8a term=,bytes=[],startOffset=0,endOffset=0,positionIncrement=1,boost=1.0,keyword=false)
[junit4] 2> Conditional:org.apache.lucene.analysis.miscellaneous.ScandinavianNormalizationFilter(OneTimeWrapper@61a73505 term=,bytes=[],startOffset=0,endOffset=0,positionIncrement=1,boost=1.0,keyword=false)
[junit4] 2> org.apache.lucene.analysis.hu.HungarianLightStemFilter(ValidatingTokenFilter@1610e1d6 term=,bytes=[],startOffset=0,endOffset=0,positionIncrement=1,boost=1.0,keyword=false)
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestRandomChains -Dtests.method=testRandomChainsWithLargeStrings -Dtests.seed=2491B86F805356D3 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=en-SB -Dtests.timezone=Asia/Taipei -Dtests.asserts=true -Dtests.file.encoding=UTF-8
[junit4] ERROR 3.93s J0 | TestRandomChains.testRandomChainsWithLargeStrings <<<
[junit4] > Throwable #1: java.lang.NumberFormatException: For input string: "ꡗ 檓젏
[junit4] > 쀖 cpbtmd nhnbpm"
[junit4] > at __randomizedtesting.SeedInfo.seed([2491B86F805356D3:4ECA077ED91D7620]:0)
[junit4] > at java.base/jdk.internal.math.FloatingDecimal.readJavaFormatString(FloatingDecimal.java:2054)
[junit4] > at java.base/jdk.internal.math.FloatingDecimal.parseFloat(FloatingDecimal.java:122)
[junit4] > at java.base/java.lang.Float.parseFloat(Float.java:455)
[junit4] > at org.apache.lucene.analysis.boost.DelimitedBoostTokenFilter.incrementToken(DelimitedBoostTokenFilter.java:52)
[junit4] > at org.apache.lucene.analysis.miscellaneous.ConditionalTokenFilter.incrementToken(ConditionalTokenFilter.java:186)
[junit4] > at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
[junit4] > at org.apache.lucene.analysis.gl.GalicianMinimalStemFilter.incrementToken(GalicianMinimalStemFilter.java:48)
[junit4] > at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
[junit4] > at org.apache.lucene.analysis.miscellaneous.ConditionalTokenFilter.incrementToken(ConditionalTokenFilter.java:174)
[junit4] > at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
[junit4] > at org.apache.lucene.analysis.hu.HungarianLightStemFilter.incrementToken(HungarianLightStemFilter.java:48)
[junit4] > at org.apache.lucene.analysis.ValidatingTokenFilter.incrementToken(ValidatingTokenFilter.java:77)
[junit4] > at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkAnalysisConsistency(BaseTokenStreamTestCase.java:716)
[junit4] > at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkRandomData(BaseTokenStreamTestCase.java:630)
[junit4] > at org.apache.lucene.analysis.BaseTokenStreamTestCase.checkRandomData(BaseTokenStreamTestCase.java:558)
[junit4] > at org.apache.lucene.analysis.core.TestRandomChains.testRandomChainsWithLargeStrings(TestRandomChains.java:899)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/analysis/common/test/J0/temp/lucene.analysis.core.TestRandomChains_2491B86F805356D3-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {dummy=BlockTreeOrds(blocksize=128)}, docValues:{}, maxPointsInLeafNode=705, maxMBSortInHeap=7.183027398493152, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@5c8a4fe2), locale=en-SB, timezone=Asia/Taipei
[junit4] 2> NOTE: Linux 4.4.0-170-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=8,threads=1,free=480167784,total=528482304
[junit4] 2> NOTE: All tests run in this JVM: [TestPersianNormalizationFilterFactory, TestShingleFilterFactory, TestAnalysisSPILoader, TestItalianLightStemFilter, TestDictionaryCompoundWordTokenFilterFactory, TestWordnetSynonymParser, TestAlternateCasing, TestDecimalDigitFilterFactory, TestApostropheFilter, NumericPayloadTokenFilterTest, TestCondition2, TestSwedishLightStemFilterFactory, TestStemmer, TestPatternReplaceFilterFactory, TestArabicStemFilter, TestDutchAnalyzer, WikipediaTokenizerTest, TestIgnore, TestNorwegianLightStemFilterFactory, TestCircumfix, TestLatvianStemmer, TestStandardFactories, TestCzechStemFilterFactory, TestSerbianNormalizationFilterFactory, TestPatternReplaceCharFilter, TestKeywordRepeatFilter, TestIndonesianStemmer, TestRollingCharBuffer, TestSoraniAnalyzer, TestScandinavianNormalizationFilterFactory, TestReverseStringFilter, TestOnlyInCompound, TestBengaliNormalizer, TestRandomChains]
[junit4] Completed [255/297 (1!)] on J0 in 54.13s, 2 tests, 1 error <<< FAILURES!
[...truncated 64571 lines...]
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 2118 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/2118/
2 tests failed.
FAILED: org.apache.solr.cloud.SystemCollectionCompatTest.testBackCompat
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:46871/solr/.system]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:46871/solr/.system]
at __randomizedtesting.SeedInfo.seed([3AFF599187F269A3:4A0AFA38E73AC0D5]:0)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:345)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.sendRequest(BaseCloudSolrClient.java:1143)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.requestWithRetryOnStaleState(BaseCloudSolrClient.java:906)
at org.apache.solr.client.solrj.impl.BaseCloudSolrClient.request(BaseCloudSolrClient.java:838)
at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207)
at org.apache.solr.cloud.SystemCollectionCompatTest.setupSystemCollection(SystemCollectionCompatTest.java:118)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:976)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: org.apache.solr.client.solrj.SolrServerException: Timeout occurred while waiting response from server at: http://127.0.0.1:46871/solr/.system
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:676)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:265)
at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:248)
at org.apache.solr.client.solrj.impl.LBSolrClient.doRequest(LBSolrClient.java:368)
at org.apache.solr.client.solrj.impl.LBSolrClient.request(LBSolrClient.java:296)
... 43 more
Caused by: java.net.SocketTimeoutException: Read timed out
at java.base/java.net.SocketInputStream.socketRead0(Native Method)
at java.base/java.net.SocketInputStream.socketRead(SocketInputStream.java:115)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:168)
at java.base/java.net.SocketInputStream.read(SocketInputStream.java:140)
at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137)
at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153)
at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259)
at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163)
at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:83)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:56)
at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:564)
... 47 more
FAILED: org.apache.solr.cloud.hdfs.HdfsSyncSliceTest.test
Error Message:
expected:<5> but was:<4>
Stack Trace:
java.lang.AssertionError: expected:<5> but was:<4>
at __randomizedtesting.SeedInfo.seed([3AFF599187F269A3:B2AB664B290E045B]: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.cloud.SyncSliceTest.test(SyncSliceTest.java:150)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:1082)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1054)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 12914 lines...]
[junit4] Suite: org.apache.solr.cloud.SystemCollectionCompatTest
[junit4] 2> 44013 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/server/solr/configsets/_default/conf'
[junit4] 2> 44013 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/data-dir-10-001
[junit4] 2> 44014 WARN (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1
[junit4] 2> 44015 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 44015 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", ssl=0.0/0.0, value=0.0/0.0, clientAuth=0.0/0.0)
[junit4] 2> 44016 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 44016 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001
[junit4] 2> 44016 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 44016 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 44016 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 44116 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:37313
[junit4] 2> 44117 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:37313
[junit4] 2> 44117 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:37313
[junit4] 2> 44117 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 37313
[junit4] 2> 44118 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44120 INFO (zkConnectionManagerCallback-215-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44120 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44122 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44123 INFO (zkConnectionManagerCallback-217-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44123 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44124 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44125 INFO (zkConnectionManagerCallback-219-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44125 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44275 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 44275 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 44275 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 44276 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 44276 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ...
[junit4] 2> 44276 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.Server jetty-9.4.24.v20191120; built: 2019-11-20T21:37:49.771Z; git: 363d5f2df3a8a28de40604320230664b9c793c16; jvm 11.0.4+10-LTS
[junit4] 2> 44302 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 44302 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 44302 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 44306 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 44306 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 44306 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 44306 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c38bf90{/solr,null,AVAILABLE}
[junit4] 2> 44308 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@39971a6{/solr,null,AVAILABLE}
[junit4] 2> 44308 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@27875929{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:46871}
[junit4] 2> 44308 INFO (jetty-launcher-220-thread-1) [ ] o.e.j.s.Server Started @44369ms
[junit4] 2> 44308 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=46871}
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5746b432{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:41489}
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.e.j.s.Server Started @44370ms
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=41489}
[junit4] 2> 44309 ERROR (jetty-launcher-220-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr
[junit4] 2> 44309 ERROR (jetty-launcher-220-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-03-01T04:34:56.910750Z
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 9.0.0
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr
[junit4] 2> 44309 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-03-01T04:34:56.910842Z
[junit4] 2> 44314 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44314 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44322 INFO (zkConnectionManagerCallback-222-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44322 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44322 INFO (zkConnectionManagerCallback-224-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44322 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44323 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 44323 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 44430 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 44430 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true]
[junit4] 2> 44432 WARN (jetty-launcher-220-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@69c51ec9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44432 WARN (jetty-launcher-220-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@17dff3d8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44433 WARN (jetty-launcher-220-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@69c51ec9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44433 WARN (jetty-launcher-220-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@17dff3d8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44443 WARN (jetty-launcher-220-thread-2) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2407a506[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44443 WARN (jetty-launcher-220-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2407a506[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44443 WARN (jetty-launcher-220-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2b116e43[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44444 WARN (jetty-launcher-220-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2b116e43[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 44444 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37313/solr
[junit4] 2> 44445 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:37313/solr
[junit4] 2> 44454 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44458 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44468 INFO (zkConnectionManagerCallback-236-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44469 INFO (jetty-launcher-220-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44470 INFO (zkConnectionManagerCallback-238-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44470 INFO (jetty-launcher-220-thread-2) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44572 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44573 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44578 INFO (zkConnectionManagerCallback-240-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44578 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44578 INFO (zkConnectionManagerCallback-242-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44578 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44711 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:41489_solr
[junit4] 2> 44712 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.Overseer Overseer (id=73332851844055048-127.0.0.1:41489_solr-n_0000000000) starting
[junit4] 2> 44726 INFO (OverseerStateUpdate-73332851844055048-127.0.0.1:41489_solr-n_0000000000) [n:127.0.0.1:41489_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:41489_solr
[junit4] 2> 44731 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41489_solr
[junit4] 2> 44734 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 44734 WARN (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 44738 INFO (zkCallback-241-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 44753 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 44758 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:46871_solr as DOWN
[junit4] 2> 44759 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores
[junit4] 2> 44759 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46871_solr
[junit4] 2> 44760 INFO (zkCallback-241-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 44761 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 44762 WARN (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.CoreContainer Not all security plugins configured! authentication=disabled authorization=disabled. Solr is only as secure as you make it. Consider configuring authentication/authorization before exposing Solr to users internal or external. See https://s.apache.org/solrsecurity for more info
[junit4] 2> 44772 INFO (zkCallback-239-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 44782 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 44783 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 44811 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41489.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44824 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41489.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44824 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_41489.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44826 INFO (jetty-launcher-220-thread-2) [n:127.0.0.1:41489_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node2/.
[junit4] 2> 44827 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44834 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44834 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 44835 INFO (jetty-launcher-220-thread-1) [n:127.0.0.1:46871_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/.
[junit4] 2> 44878 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.MiniSolrCloudCluster waitForAllNodes: numServers=2
[junit4] 2> 44880 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 44884 INFO (zkConnectionManagerCallback-255-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 44884 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 44885 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 44886 INFO (SUITE-SystemCollectionCompatTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37313/solr ready
[junit4] 2> 45184 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testBackCompat
[junit4] 2> 45186 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 45194 INFO (zkConnectionManagerCallback-260-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 45194 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 45195 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 45196 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:37313/solr ready
[junit4] 2> 45201 INFO (qtp1501643122-608) [n:127.0.0.1:41489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :overseerstatus with params action=OVERSEERSTATUS&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 45217 INFO (qtp1501643122-608) [n:127.0.0.1:41489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={action=OVERSEERSTATUS&wt=javabin&version=2} status=0 QTime=16
[junit4] 2> 45219 INFO (qtp1501643122-613) [n:127.0.0.1:41489_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:46871_solr&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 45230 INFO (OverseerThreadFactory-182-thread-2-processing-n:127.0.0.1:41489_solr) [n:127.0.0.1:41489_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system
[junit4] 2> 45230 INFO (OverseerCollectionConfigSetProcessor-73332851844055048-127.0.0.1:41489_solr-n_0000000000) [n:127.0.0.1:41489_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> 45334 WARN (OverseerThreadFactory-182-thread-2-processing-n:127.0.0.1:41489_solr) [n:127.0.0.1:41489_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 2 on collection .system is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance.
[junit4] 2> 45337 INFO (OverseerStateUpdate-73332851844055048-127.0.0.1:41489_solr-n_0000000000) [n:127.0.0.1:41489_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n1",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46871/solr",
[junit4] 2> "node_name":"127.0.0.1:46871_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 45339 INFO (OverseerStateUpdate-73332851844055048-127.0.0.1:41489_solr-n_0000000000) [n:127.0.0.1:41489_solr ] o.a.s.c.o.SliceMutator createReplica() {
[junit4] 2> "operation":"ADDREPLICA",
[junit4] 2> "collection":".system",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":".system_shard1_replica_n2",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:46871/solr",
[junit4] 2> "node_name":"127.0.0.1:46871_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "waitForFinalState":"false"}
[junit4] 2> 45548 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 45550 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr x:.system_shard1_replica_n2 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 45577 WARN (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig You should not use LATEST as luceneMatchVersion property: if you use this setting, and then Solr upgrades to a newer release of Lucene, sizable changes may happen. If precise back compatibility is important then you should instead explicitly specify an actual Lucene version.
[junit4] 2> 45577 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 45579 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 45596 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 45597 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead
[junit4] 2> 45600 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 45600 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 45604 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 45604 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 45610 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema
[junit4] 2> 45610 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchema Managed schema znode at /configs/.system/managed-schema already exists - no need to create it
[junit4] 2> 45613 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak
[junit4] 2> 45613 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n2' using configuration from configset .system, trusted=true
[junit4] 2> 45614 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.core..system.shard1.replica_n2' (registry 'solr.core..system.shard1.replica_n2') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 45614 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [[.system_shard1_replica_n2] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/.system_shard1_replica_n2], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/./.system_shard1_replica_n2/data/]
[junit4] 2> 45615 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, the non-managed schema /configs/.system/schema.xml no longer exists.
[junit4] 2> 45615 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from configset .system, trusted=true
[junit4] 2> 45615 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 45615 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 45687 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 45687 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 45689 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 45689 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 45691 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@54d0bfbc[.system_shard1_replica_n1] main]
[junit4] 2> 45692 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 45692 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 45694 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 45694 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 45694 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 45695 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 45695 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 45707 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659934918110609408
[junit4] 2> 45709 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 45709 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 45712 INFO (searcherExecutor-192-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@54d0bfbc[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 45716 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0}, version=0}
[junit4] 2> 45716 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@351af873[.system_shard1_replica_n2] main]
[junit4] 2> 45716 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 45719 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 45720 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 45721 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 45721 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 45721 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Retrieved schema version 0 from ZooKeeper
[junit4] 2> 45723 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema [.system_shard1_replica_n2] Schema name=_system collection or core
[junit4] 2> 45727 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 45731 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Finished refreshing schema in 5 ms
[junit4] 2> 45731 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 45731 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1659934918135775232
[junit4] 2> 45735 INFO (searcherExecutor-191-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@351af873[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 45736 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=0, core_node4=0}, version=1}
[junit4] 2> 45737 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1
[junit4] 2> 46224 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 46224 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 46224 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:46871/solr/.system_shard1_replica_n1/
[junit4] 2> 46229 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=http://127.0.0.1:46871/solr START replicas=[http://127.0.0.1:46871/solr/.system_shard1_replica_n2/] nUpdates=100
[junit4] 2> 46230 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.PeerSync PeerSync: core=.system_shard1_replica_n1 url=http://127.0.0.1:46871/solr DONE. We have no versions. sync failed.
[junit4] 2> 46232 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 46235 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 46235 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 46235 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/73332851844055047-core_node3-n_0000000000
[junit4] 2> 46237 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:46871/solr/.system_shard1_replica_n1/ shard1
[junit4] 2> 46339 INFO (zkCallback-239-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46340 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 46342 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node3&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=794
[junit4] 2> 46442 INFO (zkCallback-239-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46442 INFO (zkCallback-239-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46741 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node4&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n2&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1191
[junit4] 2> 46743 INFO (qtp1501643122-613) [n:127.0.0.1:41489_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> 46845 INFO (zkCallback-241-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46845 INFO (zkCallback-239-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46845 INFO (zkCallback-239-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2])
[junit4] 2> 46845 INFO (qtp1501643122-613) [n:127.0.0.1:41489_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={maxShardsPerNode=2&name=.system&nrtReplicas=2&action=CREATE&numShards=1&createNodeSet=127.0.0.1:46871_solr&wt=javabin&version=2} status=0 QTime=1626
[junit4] 2> 46846 INFO (TEST-SystemCollectionCompatTest.testBackCompat-seed#[3AFF599187F269A3]) [ ] o.a.s.c.MiniSolrCloudCluster waitForActiveCollection: .system
[junit4] 2> 46857 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node3=1, core_node4=1}, version=2}
[junit4] 2> 46865 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:46871/solr/.system_shard1_replica_n1/&wt=javabin&version=2}{add=[17094603afbToiwvsimvz26e5ja6of7kqicl (1659934919312277504)]} 0 1
[junit4] 2> 46867 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={wt=javabin&version=2}{add=[17094603afbToiwvsimvz26e5ja6of7kqicl (1659934919312277504)]} 0 14
[junit4] 2> 46868 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659934919328006144,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 46868 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@363d84d9 commitCommandVersion:1659934919328006144
[junit4] 2> 46871 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 start commit{_version_=1659934919331151872,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 46872 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@45443397 commitCommandVersion:1659934919331151872
[junit4] 2> 46881 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3574250a[.system_shard1_replica_n1] main]
[junit4] 2> 46881 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@36cb1f54[.system_shard1_replica_n2] main]
[junit4] 2> 46884 INFO (searcherExecutor-191-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n2 c:.system s:shard1 r:core_node4) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.SolrCore [.system_shard1_replica_n2] Registered new searcher Searcher@36cb1f54[.system_shard1_replica_n2] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4, timestamp=1583037299477}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 46884 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 46884 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 46884 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:46871/solr/.system_shard1_replica_n1/&commit_end_point=replicas&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 13
[junit4] 2> 46885 INFO (searcherExecutor-192-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@3574250a[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4, timestamp=1583037299477}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 46886 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.p.LogUpdateProcessorFactory [.system_shard1_replica_n1] webapp=/solr path=/update params={_stateVer_=.system:6&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 17
[junit4] 2> 46890 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 46891 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={action=STATUS&indexInfo=true&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 46894 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.S.Request [.system_shard1_replica_n1] webapp=/solr path=/schema params={wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 46899 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SchemaManager managed schema loaded . version : 1
[junit4] 2> 46901 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 46904 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 46911 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.ZkController Persisted config data to node /configs/.system/schema.xml.bak
[junit4] 2> 46912 INFO (Thread-99) [ ] o.a.s.c.SolrCore config update listener called for core .system_shard1_replica_n1
[junit4] 2> 46913 INFO (Thread-99) [ ] o.a.s.c.SolrCore core reload .system_shard1_replica_n1
[junit4] 2> 46918 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 46925 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 46929 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 46929 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 46967 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 46967 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 47037 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs;
[junit4] 2> 47037 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 47039 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1369c4b9[.system_shard1_replica_n1] main]
[junit4] 2> 47040 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system
[junit4] 2> 47041 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system
[junit4] 2> 47041 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema
[junit4] 2> 47041 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47041 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
[junit4] 2> 47047 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 47048 INFO (searcherExecutor-201-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@1369c4b9[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={java.vendor=Oracle Corporation, os=Linux, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4, timestamp=1583037299477}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 47049 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.SolrIndexSearcher Opening [Searcher@12907263[.system_shard1_replica_n1] main]
[junit4] 2> 47054 INFO (searcherExecutor-201-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@12907263[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(9.0.0):C1:[diagnostics={os=Linux, java.vendor=Oracle Corporation, os.version=4.15.0-54-generic, java.runtime.version=11.0.4+10-LTS, os.arch=amd64, source=flush, lucene.version=9.0.0, java.vm.version=11.0.4+10-LTS, java.version=11.0.4, timestamp=1583037299477}]:[attributes={Lucene50StoredFieldsFormat.mode=BEST_SPEED}])))}
[junit4] 2> 47054 INFO (qtp692101745-607) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Waiting up to 599 secs for 1 replicas to apply schema update version 2 for collection .system
[junit4] 2> 47056 INFO (Thread-99) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 47060 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47061 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47061 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 47062 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47063 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47063 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47063 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47063 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47064 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47065 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47065 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47065 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47065 INFO (Thread-99) [ ] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core
[junit4] 2> 47066 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47066 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47066 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47067 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47069 INFO (Thread-99) [ ] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id
[junit4] 2> 47069 INFO (Thread-99) [ ] o.a.s.c.CoreContainer Reloading SolrCore '.system_shard1_replica_n1' using configuration from configset .system
[junit4] 2> 47070 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47070 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47070 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47070 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47084 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47084 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47084 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47085 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47086 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47087 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47087 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47087 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47090 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47091 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47091 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47091 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47098 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47099 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47099 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47100 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47101 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47101 INFO (Thread-99) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_46871.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@121f7612
[junit4] 2> 47101 INFO (Thread-99) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J0/temp/solr.cloud.SystemCollectionCompatTest_3AFF599187F269A3-001/tempDir-001/node1/./.system_shard1_replica_n1/data/]
[junit4] 2> 47102 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47102 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47102 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47103 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47103 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47103 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47104 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47106 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47107 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47107 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47107 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47108 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47108 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47108 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47109 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47111 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47112 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47112 INFO (qtp692101745-612) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47112 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47113 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47113 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47113 INFO (qtp692101745-605) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 47114 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47114 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47115 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4] 2> 47115 INFO (qtp692101745-609) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.c.S.Request [.system_shard1_replica_n2] webapp=/solr path=/schema/zkversion params={refreshIfBelowVersion=2&wt=javabin&version=2} status=0 QTime=1
[junit4] 2> 47116 ERROR (managedSchemaExecutor-205-thread-1-processing-n:127.0.0.1:46871_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node3) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node3 x:.system_shard1_replica_n1 ] o.a.s.s.ManagedIndexSchema Replica http://127.0.0.1:46871/solr/.system_shard1_replica_n2/ returned schema version 0 and has not applied schema version 2
[junit4] 2> 47119 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.h.SchemaHandler REFRESHING SCHEMA (refreshIfBelowVersion=2, currentVersion=0) before returning version!
[junit4] 2> 47120 INFO (qtp692101745-610) [n:127.0.0.1:46871_solr c:.system s:shard1 r:core_node4 x:.system_shard1_replica_n2 ] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest
[junit4]
[...truncated too long message...]
.hadoop/hadoop-hdfs/tests/hadoop-hdfs-3.2.0-tests.jar!/webapps/static,UNAVAILABLE}
[junit4] 2> 4787238 WARN (BP-887752561-127.0.0.1-1583042004429 heartbeating to localhost.localdomain/127.0.0.1:40417) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 4787238 WARN (BP-887752561-127.0.0.1-1583042004429 heartbeating to localhost.localdomain/127.0.0.1:40417) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-887752561-127.0.0.1-1583042004429 (Datanode Uuid e483f918-0955-431d-88fe-a6c2a64bab84) service to localhost.localdomain/127.0.0.1:40417
[junit4] 2> 4787255 WARN (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.a.h.h.s.d.DirectoryScanner DirectoryScanner: shutdown has been called
[junit4] 2> 4787260 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.w.WebAppContext@1d1d8ce1{datanode,/,null,UNAVAILABLE}{jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-3.2.0-tests.jar!/webapps/datanode}
[junit4] 2> 4787260 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@5f9ea203{HTTP/1.1,[http/1.1]}{localhost:0}
[junit4] 2> 4787260 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 4787260 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@31bd9f90{static,/static,jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-3.2.0-tests.jar!/webapps/static,UNAVAILABLE}
[junit4] 2> 4787261 WARN (BP-887752561-127.0.0.1-1583042004429 heartbeating to localhost.localdomain/127.0.0.1:40417) [ ] o.a.h.h.s.d.IncrementalBlockReportManager IncrementalBlockReportManager interrupted
[junit4] 2> 4787261 WARN (BP-887752561-127.0.0.1-1583042004429 heartbeating to localhost.localdomain/127.0.0.1:40417) [ ] o.a.h.h.s.d.DataNode Ending block pool service for: Block pool BP-887752561-127.0.0.1-1583042004429 (Datanode Uuid 5f66c69a-c4a9-48a8-8e2e-d10fd21a8707) service to localhost.localdomain/127.0.0.1:40417
[junit4] 2> 4787282 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.w.WebAppContext@6e2ffa82{hdfs,/,null,UNAVAILABLE}{jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-3.2.0-tests.jar!/webapps/hdfs}
[junit4] 2> 4787282 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@2f799fe0{HTTP/1.1,[http/1.1]}{localhost.localdomain:0}
[junit4] 2> 4787282 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 4787282 INFO (SUITE-HdfsSyncSliceTest-seed#[3AFF599187F269A3]-worker) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@6c8e3092{static,/static,jar:file:/home/jenkins/.ivy2/cache/org.apache.hadoop/hadoop-hdfs/tests/hadoop-hdfs-3.2.0-tests.jar!/webapps/static,UNAVAILABLE}
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.cloud.hdfs.HdfsSyncSliceTest_3AFF599187F269A3-001
[junit4] 2> Mar 01, 2020 5:53:59 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 33 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {rnd_b=FST50, multiDefault=Lucene84, a_t=Lucene84, _root_=BlockTreeOrds(blocksize=128), id=FST50, text=PostingsFormat(name=MockRandom)}, docValues:{range_facet_l_dv=DocValuesFormat(name=Asserting), _version_=DocValuesFormat(name=Lucene80), range_facet_i_dv=DocValuesFormat(name=Lucene80), intDvoDefault=DocValuesFormat(name=Asserting), timestamp=DocValuesFormat(name=Lucene80)}, maxPointsInLeafNode=1904, maxMBSortInHeap=6.773812629038938, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@4e1bbb3d), locale=it-VA, timezone=Canada/Eastern
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=5,free=155173368,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestMiniSolrCloudClusterSSL, CdcrBootstrapTest, TestConfigSetsAPI, TestSchemalessBufferedUpdates, TestSolrConfigHandlerCloud, ReplaceNodeNoTargetTest, DateMathParserTest, TestHighlightDedupGrouping, BadComponentTest, SolrJmxReporterTest, JWTAuthPluginIntegrationTest, TestAuthenticationFramework, TestQuerySenderListener, SparseHLLTest, TriggerSetPropertiesIntegrationTest, ConnectionManagerTest, DistributedExpandComponentTest, SolrLogAuditLoggerPluginTest, TestDistribIDF, TestInPlaceUpdatesStandalone, TestFieldCacheReopen, XmlUpdateRequestHandlerTest, DistributedFacetPivotWhiteBoxTest, TestSimScenario, TestCoreContainer, TestRebalanceLeaders, TestHashPartitioner, TestCSVResponseWriter, SearchRateTriggerTest, InfixSuggestersTest, TestRemoteStreaming, CacheHeaderTest, PeerSyncWithIndexFingerprintCachingTest, ClusterStateUpdateTest, TestSystemCollAutoCreate, ConfigureRecoveryStrategyTest, UniqFieldsUpdateProcessorFactoryTest, DistributedQueueTest, SpellPossibilityIteratorTest, SolrShardReporterTest, TestClusterStateMutator, TestPullReplica, TestSolrXml, BasicDistributedZk2Test, CdcrRequestHandlerTest, DeleteReplicaTest, SolrCLIZkUtilsTest, HdfsRecoverLeaseTest, IndexSizeTriggerMixedBoundsTest, MissingSegmentRecoveryTest, TestShardHandlerFactory, TestSimNodeAddedTrigger, TestDocTermOrds, DistribCursorPagingTest, TestSolrTestCaseJ4, HighlighterMaxOffsetTest, TestGraphMLResponseWriter, TestDeprecatedFilters, PreAnalyzedUpdateProcessorTest, RestartWhileUpdatingTest, ZkStateWriterTest, CursorMarkTest, TestImpersonationWithHadoopAuth, SSLMigrationTest, MetricsHistoryIntegrationTest, SolrInfoBeanTest, TestTolerantUpdateProcessorCloud, TestConfigSetImmutable, RangeFacetCloudTest, TestFieldTypeResource, TestCodecSupport, WordBreakSolrSpellCheckerTest, MetricTriggerIntegrationTest, TestMaxScoreQueryParser, TestFieldSortValues, NumberUtilsTest, BinaryUpdateRequestHandlerTest, PingRequestHandlerTest, TestSchemaSimilarityResource, TestRealTimeGet, TestPhraseSuggestions, ClassificationUpdateProcessorTest, CurrencyFieldTypeTest, QueryElevationComponentTest, SolrCoreMetricManagerTest, ChaosMonkeySafeLeaderWithPullReplicasTest, StatelessScriptUpdateProcessorFactoryTest, TestLegacyNumericUtils, TestPushWriter, TestRuleBasedAuthorizationPlugin, TestLazyCores, SecurityConfHandlerTest, TestSolrQueryParser, TestDistributedMap, CategoryRoutedAliasUpdateProcessorTest, TestLMDirichletSimilarityFactory, TestSearcherReuse, RulesTest, PreAnalyzedFieldManagedSchemaCloudTest, AnalyticsMergeStrategyTest, SchemaVersionSpecificBehaviorTest, ForceLeaderTest, TestSafeXMLParsing, SearchHandlerTest, CollectionsAPIDistributedZkTest, BitVectorTest, TestNumericTerms32, NodeMarkersRegistrationTest, TestChildDocTransformerHierarchy, TestCopyFieldCollectionResource, HealthCheckHandlerTest, TestJettySolrRunner, PackageManagerCLITest, TestStressLucene, DocValuesMissingTest, JavabinLoaderTest, AutoAddReplicasPlanActionTest, TestWaitForStateWithJettyShutdowns, TestNonDefinedSimilarityFactory, TriggerCooldownIntegrationTest, TestHttpServletCarrier, TestPivotHelperCode, TestIndexSearcher, IndexBasedSpellCheckerTest, CustomTermsComponentTest, TestConfigsApi, CloudExitableDirectoryReaderTest, TestDistributedStatsComponentCardinality, FieldMutatingUpdateProcessorTest, TestInPlaceUpdateWithRouteField, TestAtomicUpdateErrorCases, TestCoreBackup, TestSolr4Spatial, AuthToolTest, TestCloudJSONFacetSKG, ZkSolrClientTest, CollectionReloadTest, TestRSAKeyPair, TestCloudPivotFacet, TestMaxTokenLenTokenizer, TestQueryTypes, SuggesterTest, EnumFieldTest, OverseerStatusTest, TestComplexPhraseQParserPlugin, ExitableDirectoryReaderTest, TestReplicaProperties, TestDocumentBuilder, TestRandomDVFaceting, TestRandomFaceting, TestTolerantSearch, TestTrie, PathHierarchyTokenizerFactoryTest, ProtectedTermFilterFactoryTest, TestLuceneMatchVersion, TestReversedWildcardFilterFactory, TestWordDelimiterFilterFactory, TestEmbeddedSolrServerAdminHandler, TestEmbeddedSolrServerConstructors, ActionThrottleTest, AddReplicaTest, BasicDistributedZkTest, CreateRoutedAliasTest, DeleteInactiveReplicaTest, DeleteShardTest, DistributedVersionInfoTest, HttpPartitionWithTlogReplicasTest, LeaderTragicEventTest, LeaderVoteWaitTimeoutTest, MultiThreadedOCPTest, NestedShardedAtomicUpdateTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverriddenZkACLAndCredentialsProvidersTest, RecoveryAfterSoftCommitTest, ReindexCollectionTest, SplitShardTest, TestCloudDeleteByQuery, TestCloudInspectUtil, TestCloudRecovery, TestCloudRecovery2, TestConfigSetsAPIZkFailure, TestCryptoKeys, TestExactSharedStatsCacheCloud, TestLeaderElectionWithEmptyReplica, TestOnReconnectListenerSupport, TestSSLRandomization, TestSizeLimitedDistributedMap, TestSkipOverseerOperations, TestStressInPlaceUpdates, TestTlogReplayVsRecovery, TestWithCollection, TestZkChroot, TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, UnloadDistributedZkTest, VMParamsZkACLAndCredentialsProvidersTest, ZkControllerTest, ZkFailoverTest, AssignTest, ConcurrentDeleteAndCreateCollectionTest, CustomCollectionTest, ShardSplitTest, NodeAddedTriggerTest, ScheduledTriggerTest, TestSimComputePlanAction, TestSimDistribStateManager, TestSimDistributedQueue, TestSimUtils, TestSnapshotCloudManager, CdcrVersionReplicationTest, CdcrWithNodesRestartsTest, HdfsChaosMonkeyNothingIsSafeTest, HdfsRecoveryZkTest, HdfsRestartWhileUpdatingTest, HdfsSyncSliceTest]
[junit4] Completed [589/905 (2!)] on J1 in 38.57s, 1 test, 1 failure <<< FAILURES!
[...truncated 53624 lines...]
[JENKINS] Lucene-Solr-NightlyTests-master - Build # 2117 - Still
Unstable
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/2117/
1 tests failed.
FAILED: org.apache.lucene.codecs.blockterms.TestVarGapFixedIntervalPostingsFormat.testCheckIntegrityReadsAllBytes
Error Message:
Some files have not been open: [write.lock, extra0]
Stack Trace:
java.lang.AssertionError: Some files have not been open: [write.lock, extra0]
at __randomizedtesting.SeedInfo.seed([4D39CA02B9EFC32:79118D7C8A60289B]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.lucene.index.BaseIndexFileFormatTestCase.testCheckIntegrityReadsAllBytes(BaseIndexFileFormatTestCase.java:899)
at org.apache.lucene.index.BasePostingsFormatTestCase.testCheckIntegrityReadsAllBytes(BasePostingsFormatTestCase.java:86)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:566)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:942)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:978)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:992)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:834)
Build Log:
[...truncated 7501 lines...]
[junit4] Suite: org.apache.lucene.codecs.blockterms.TestVarGapFixedIntervalPostingsFormat
[junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestVarGapFixedIntervalPostingsFormat -Dtests.method=testCheckIntegrityReadsAllBytes -Dtests.seed=4D39CA02B9EFC32 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/test-data/enwiki.random.lines.txt -Dtests.locale=kln-KE -Dtests.timezone=Indian/Comoro -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 0.02s J0 | TestVarGapFixedIntervalPostingsFormat.testCheckIntegrityReadsAllBytes <<<
[junit4] > Throwable #1: java.lang.AssertionError: Some files have not been open: [write.lock, extra0]
[junit4] > at __randomizedtesting.SeedInfo.seed([4D39CA02B9EFC32:79118D7C8A60289B]:0)
[junit4] > at org.apache.lucene.index.BaseIndexFileFormatTestCase.testCheckIntegrityReadsAllBytes(BaseIndexFileFormatTestCase.java:899)
[junit4] > at org.apache.lucene.index.BasePostingsFormatTestCase.testCheckIntegrityReadsAllBytes(BasePostingsFormatTestCase.java:86)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4] > at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
[junit4] > at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4] > at java.base/java.lang.reflect.Method.invoke(Method.java:566)
[junit4] > at java.base/java.lang.Thread.run(Thread.java:834)
[junit4] 2> NOTE: leaving temporary files on disk at: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/build/codecs/test/J0/temp/lucene.codecs.blockterms.TestVarGapFixedIntervalPostingsFormat_4D39CA02B9EFC32-001
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene84): {}, docValues:{}, maxPointsInLeafNode=1647, maxMBSortInHeap=6.279172380812195, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@290bbd4e), locale=kln-KE, timezone=Indian/Comoro
[junit4] 2> NOTE: Linux 4.15.0-54-generic amd64/Oracle Corporation 11.0.4 (64-bit)/cpus=4,threads=1,free=222724912,total=499122176
[junit4] 2> NOTE: All tests run in this JVM: [TestSimpleTextStoredFieldsFormat, TestOrdsBlockTree, TestSimpleTextFieldInfoFormat, TestFSTDictionary, TestFixedGapPostingsFormat, TestVarGapDocFreqIntervalPostingsFormat, TestVarGapFixedIntervalPostingsFormat]
[junit4] Completed [14/24 (1!)] on J0 in 247.94s, 26 tests, 1 failure <<< FAILURES!
[...truncated 61050 lines...]