You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2020/05/24 16:53:18 UTC
[JENKINS-Experimental-GC] Lucene-Solr-master-MacOSX (64bit/jdk-14)
- Build # 6064 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6064/
Java: 64bit/jdk-14 -XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC
2 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CleanupOldIndexTest
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.cloud.CleanupOldIndexTest: 1) Thread[id=13693, name=SessionTracker, state=TIMED_WAITING, group=TGRP-CleanupOldIndexTest] at java.base@14/java.lang.Thread.sleep(Native Method) at app//org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:151)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CleanupOldIndexTest:
1) Thread[id=13693, name=SessionTracker, state=TIMED_WAITING, group=TGRP-CleanupOldIndexTest]
at java.base@14/java.lang.Thread.sleep(Native Method)
at app//org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:151)
at __randomizedtesting.SeedInfo.seed([E01459883CD27B7F]:0)
FAILED: org.apache.solr.core.TestCustomStream.testDynamicLoadingCustomStream
Error Message:
{ "responseHeader":{ "status":500, "QTime":30083}, "errorMessages":["3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]\n"], "WARNING":"This response format is experimental. It is likely to change in the future.", "error":{ "metadata":[ "error-class","org.apache.solr.common.SolrException", "root-error-class","org.apache.solr.common.SolrException"], "msg":"3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]", "trace":"org.apache.solr.common.SolrException: 3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]\n\tat org.apache.solr.handler.SolrConfigHandler.waitForAllReplicasState(SolrConfigHandler.java:821)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handleCommands(SolrConfigHandler.java:528)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handlePOST(SolrConfigHandler.java:365)\n\tat org.apache.solr.handler.SolrConfigHandler.handleRequestBody(SolrConfigHandler.java:139)\n\tat org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:209)\n\tat org.apache.solr.core.SolrCore.execute(SolrCore.java:2591)\n\tat org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:803)\n\tat org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:582)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:415)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)\n\tat org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)\n\tat org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)\n\tat org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.server.Server.handle(Server.java:500)\n\tat org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)\n\tat org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)\n\tat org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)\n\tat org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)\n\tat org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)\n\tat org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)\n\tat org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)\n\tat java.base/java.lang.Thread.run(Thread.java:832)\n", "code":500}} expected null, but was:<[3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/] ]>
Stack Trace:
java.lang.AssertionError: {
"responseHeader":{
"status":500,
"QTime":30083},
"errorMessages":["3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]\n"],
"WARNING":"This response format is experimental. It is likely to change in the future.",
"error":{
"metadata":[
"error-class","org.apache.solr.common.SolrException",
"root-error-class","org.apache.solr.common.SolrException"],
"msg":"3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]",
"trace":"org.apache.solr.common.SolrException: 3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]\n\tat org.apache.solr.handler.SolrConfigHandler.waitForAllReplicasState(SolrConfigHandler.java:821)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handleCommands(SolrConfigHandler.java:528)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handlePOST(SolrConfigHandler.java:365)\n\tat org.apache.solr.handler.SolrConfigHandler.handleRequestBody(SolrConfigHandler.java:139)\n\tat org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:209)\n\tat org.apache.solr.core.SolrCore.execute(SolrCore.java:2591)\n\tat org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:803)\n\tat org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:582)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:415)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)\n\tat org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)\n\tat org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)\n\tat org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.server.Server.handle(Server.java:500)\n\tat org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)\n\tat org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)\n\tat org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)\n\tat org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)\n\tat org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)\n\tat org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)\n\tat org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)\n\tat java.base/java.lang.Thread.run(Thread.java:832)\n",
"code":500}}
expected null, but was:<[3 out of 5 the property overlay to be of version 0 within 30 seconds! Failed cores: [http://127.0.0.1:62135/collection1_shard2_replica_n5/, http://127.0.0.1:62139/collection1_shard1_replica_n1/, http://127.0.0.1:62147/collection1_shard1_replica_n7/]
]>
at __randomizedtesting.SeedInfo.seed([E01459883CD27B7F:90A150AAC62830C8]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotNull(Assert.java:755)
at org.junit.Assert.assertNull(Assert.java:737)
at org.apache.solr.core.TestSolrConfigHandler.runConfigCommand(TestSolrConfigHandler.java:179)
at org.apache.solr.core.TestCustomStream.testDynamicLoadingCustomStream(TestCustomStream.java:58)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.base/java.lang.reflect.Method.invoke(Method.java:564)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1754)
at com.carrotsearch.randomizedtesting.RandomizedRunner$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:1081)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1053)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:819)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:470)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:951)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:887)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:898)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:370)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.lambda$forkTimeoutingTask$0(ThreadLeakControl.java:826)
at java.base/java.lang.Thread.run(Thread.java:832)
Build Log:
[...truncated 12866 lines...]
[junit4] Suite: org.apache.solr.core.TestCustomStream
[junit4] 2> 10391 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 10391 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 10394 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/data-dir-2-001
[junit4] 2> 10396 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true
[junit4] 2> 10433 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 10433 INFO (SUITE-TestCustomStream-seed#[E01459883CD27B7F]-worker) [ ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /
[junit4] 2> 10504 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 10512 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port: 0.0.0.0/0.0.0.0:0
[junit4] 2> 10513 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 10722 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer start zk server on port: 62120
[junit4] 2> 10723 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer waitForServerUp: 127.0.0.1:62120
[junit4] 2> 10728 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:62120
[junit4] 2> 10738 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 62120
[junit4] 2> 10966 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 11088 INFO (zkConnectionManagerCallback-5-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 11089 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 11145 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 11203 INFO (zkConnectionManagerCallback-7-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 11205 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 11327 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 11399 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 11450 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 11484 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 11522 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 11551 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 11624 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 11662 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 11701 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 11837 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 11893 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkTestServer put /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 11975 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Will use NRT replicas unless explicitly asked otherwise
[junit4] 2> 16878 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 16878 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 16886 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 17005 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 17005 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 17009 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 17078 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2f812585{/,null,AVAILABLE}
[junit4] 2> 17105 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5004c593{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62124}
[junit4] 2> 17106 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.s.Server Started @17231ms
[junit4] 2> 17106 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/tempDir-001/control/data, hostPort=62124, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/control-001/cores, replicaType=NRT}
[junit4] 2> 17335 ERROR (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 17362 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 17363 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 17368 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 17368 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr
[junit4] 2> 17368 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T15:47:07.271508Z
[junit4] 2> 17398 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 17404 INFO (zkConnectionManagerCallback-9-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 17430 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 17634 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 17654 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/control-001/solr.xml
[junit4] 2> 18175 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 20664 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
[junit4] 2> 21453 WARN (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2b71abcc[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 21453 WARN (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2b71abcc[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 22239 WARN (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@76ec1ee2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 22242 WARN (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@76ec1ee2[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 22508 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62120/solr
[junit4] 2> 22562 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 22644 INFO (zkConnectionManagerCallback-20-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 22644 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 22917 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 23051 INFO (zkConnectionManagerCallback-22-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 23052 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 26858 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:62124_
[junit4] 2> 26910 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.Overseer Overseer (id=72097575874265092-127.0.0.1:62124_-n_0000000000) starting
[junit4] 2> 27503 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62124_
[junit4] 2> 27612 INFO (OverseerStateUpdate-72097575874265092-127.0.0.1:62124_-n_0000000000) [n:127.0.0.1:62124_ ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:62124_
[junit4] 2> 27700 INFO (OverseerStateUpdate-72097575874265092-127.0.0.1:62124_-n_0000000000) [n:127.0.0.1:62124_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 27931 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 27964 WARN (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] 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> 28626 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 29265 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 29266 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 29267 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 29484 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [n:127.0.0.1:62124_ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/control-001/cores
[junit4] 2> 29835 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 29842 INFO (zkConnectionManagerCallback-39-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 29846 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 29885 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 29996 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62120/solr ready
[junit4] 2> 31260 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&name=control_collection&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:62124_&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 31385 INFO (OverseerThreadFactory-29-thread-1-processing-n:127.0.0.1:62124_) [n:127.0.0.1:62124_ ] o.a.s.c.a.c.CreateCollectionCmd Create collection control_collection
[junit4] 2> 31945 INFO (qtp1079936242-90) [n:127.0.0.1:62124_ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 31952 INFO (qtp1079936242-90) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=29
[junit4] 2> 32088 INFO (qtp1079936242-88) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CONTAINER.cores&wt=javabin&version=2&group=solr.node} status=0 QTime=2
[junit4] 2> 32211 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ x:control_collection_shard1_replica_n1 ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=conf1&newCollection=true&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT
[junit4] 2> 33569 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0
[junit4] 2> 34374 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.s.IndexSchema Schema name=test
[junit4] 2> 36727 WARN (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.WordDelimiterFilterFactory]. Please consult documentation how to replace it accordingly.
[junit4] 2> 37376 WARN (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.GeoHashField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 37393 WARN (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.LatLonType]. Please consult documentation how to replace it accordingly.
[junit4] 2> 37411 WARN (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrResourceLoader Solr loaded a deprecated plugin/analysis class [solr.CurrencyField]. Please consult documentation how to replace it accordingly.
[junit4] 2> 39199 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
[junit4] 2> 40467 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.CoreContainer Creating SolrCore 'control_collection_shard1_replica_n1' using configuration from configset conf1, trusted=true
[junit4] 2> 40519 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.control_collection.shard1.replica_n1' (registry 'solr.core.control_collection.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 40605 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrCore [[control_collection_shard1_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/control-001/cores/control_collection_shard1_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/control-001/cores/control_collection_shard1_replica_n1/data/]
[junit4] 2> 40783 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=36, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 41963 WARN (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = requestHandler,name = /dump,class = DumpRequestHandler,attributes = {initParams=a, name=/dump, class=DumpRequestHandler},args = {defaults={a=A, b=B}}}
[junit4] 2> 44021 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 44021 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 44152 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 44152 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 44188 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=28, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.2743249306928437]
[junit4] 2> 44459 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 44544 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 44644 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 ms
[junit4] 2> 44662 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1667587379890749440
[junit4] 2> 44732 INFO (searcherExecutor-41-thread-1-processing-n:127.0.0.1:62124_ x:control_collection_shard1_replica_n1 c:control_collection s:shard1) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SolrCore [control_collection_shard1_replica_n1] Registered new searcher autowarm time: 0 ms: Collection: 'control_collection'
[junit4] 2> 44853 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ZkShardTerms Successful update of terms at /collections/control_collection/terms/shard1 to Terms{values={core_node2=0}, version=0}
[junit4] 2> 44869 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/control_collection/leaders/shard1
[junit4] 2> 45371 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 45371 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 45371 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:62124/control_collection_shard1_replica_n1/
[junit4] 2> 45379 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 45431 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.SyncStrategy http://127.0.0.1:62124/control_collection_shard1_replica_n1/ has no replicas
[junit4] 2> 45435 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/control_collection/leaders/shard1/leader after winning as /collections/control_collection/leader_elect/shard1/election/72097575874265092-core_node2-n_0000000000
[junit4] 2> 45598 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:62124/control_collection_shard1_replica_n1/ shard1
[junit4] 2> 45712 INFO (zkCallback-21-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/control_collection/state.json] for collection [control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 45714 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/control_collection/state.json] for collection [control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 45844 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ c:control_collection s:shard1 x:control_collection_shard1_replica_n1 ] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 45984 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=conf1&newCollection=true&name=control_collection_shard1_replica_n1&action=CREATE&numShards=1&collection=control_collection&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=13775
[junit4] 2> 46080 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 46150 INFO (zkCallback-21-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/control_collection/state.json] for collection [control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 46151 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/control_collection/state.json] for collection [control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 46152 INFO (zkCallback-21-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/control_collection/state.json] for collection [control_collection] has occurred - updating... (live nodes size: [1])
[junit4] 2> 46181 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf1&name=control_collection&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:62124_&wt=javabin&version=2} status=0 QTime=15042
[junit4] 2> 46184 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Waiting to see 1 active replicas in collection: control_collection
[junit4] 2> 46396 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 46416 INFO (zkConnectionManagerCallback-50-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 46421 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 46436 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 46499 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:62120/solr ready
[junit4] 2> 46526 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 46550 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params collection.configName=conf1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&stateFormat=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 46652 INFO (OverseerCollectionConfigSetProcessor-72097575874265092-127.0.0.1:62124_-n_0000000000) [n:127.0.0.1:62124_ ] 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> 46667 INFO (OverseerThreadFactory-29-thread-2-processing-n:127.0.0.1:62124_) [n:127.0.0.1:62124_ ] o.a.s.c.a.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 47181 WARN (OverseerThreadFactory-29-thread-2-processing-n:127.0.0.1:62124_) [n:127.0.0.1:62124_ ] o.a.s.c.a.c.CreateCollectionCmd It is unusual to create a collection (collection1) without cores.
[junit4] 2> 47217 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas
[junit4] 2> 47274 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={collection.configName=conf1&name=collection1&nrtReplicas=1&action=CREATE&numShards=2&createNodeSet=&stateFormat=2&wt=javabin&version=2} status=0 QTime=724
[junit4] 2> 47315 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 2 expected: 2
[junit4] 2> 47315 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 0 expected replica count: 0
[junit4] 2> 47315 INFO (watches-47-thread-1) [ ] o.a.s.c.SolrCloudTestCase active slice count: 2 expected: 2
[junit4] 2> 47315 INFO (watches-47-thread-1) [ ] o.a.s.c.SolrCloudTestCase active replica count: 0 expected replica count: 0
[junit4] 2> 47331 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 2 expected: 2
[junit4] 2> 47331 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 0 expected replica count: 0
[junit4] 2> 47333 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active slice count: 2 expected: 2
[junit4] 2> 47333 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.SolrCloudTestCase active replica count: 0 expected replica count: 0
[junit4] 2> 47333 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase Creating jetty instances pullReplicaCount=0 numOtherReplicas=4
[junit4] 2> 48755 INFO (OverseerCollectionConfigSetProcessor-72097575874265092-127.0.0.1:62124_-n_0000000000) [n:127.0.0.1:62124_ ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000002 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 50665 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-1-001 of type NRT for shard2
[junit4] 2> 50694 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 50694 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 50695 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 50698 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 50698 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 50698 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 50710 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2e283eb8{/,null,AVAILABLE}
[junit4] 2> 50715 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5eff5699{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62135}
[junit4] 2> 50715 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server Started @50840ms
[junit4] 2> 50715 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/tempDir-001/jetty1, hostPort=62135, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-1-001/cores}
[junit4] 2> 50715 ERROR (closeThreadPool-51-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 50716 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 50716 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 50716 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 50716 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr
[junit4] 2> 50716 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T15:47:40.619400Z
[junit4] 2> 50726 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 50742 INFO (zkConnectionManagerCallback-53-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 50742 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 50856 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 50857 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-1-001/solr.xml
[junit4] 2> 50878 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 51248 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
[junit4] 2> 51322 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@3598d00f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 51322 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@3598d00f[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 51407 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6002cb8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 51407 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6002cb8[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 51424 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62120/solr
[junit4] 2> 51437 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 51445 INFO (zkConnectionManagerCallback-64-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 51449 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 51596 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 51599 INFO (zkConnectionManagerCallback-66-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 51600 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 51715 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 51981 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.ZkController Publish node=127.0.0.1:62135_ as DOWN
[junit4] 2> 52009 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 52009 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62135_
[junit4] 2> 52043 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 52052 INFO (zkCallback-49-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 52053 INFO (zkCallback-65-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 52247 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 52250 WARN (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] 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> 52442 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 52783 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 52920 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 52920 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 52924 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62135_ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-1-001/cores
[junit4] 2> 53083 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.AbstractFullDistribZkTestBase waitForLiveNode: 127.0.0.1:62135_
[junit4] 2> 53419 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 2 in directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-2-001 of type NRT for shard1
[junit4] 2> 53425 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 53425 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 53425 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 53470 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 53470 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 53470 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 53473 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@22816bde{/,null,AVAILABLE}
[junit4] 2> 53485 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@72d42879{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62139}
[junit4] 2> 53485 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server Started @53611ms
[junit4] 2> 53485 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/tempDir-001/jetty2, hostPort=62139, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-2-001/cores, replicaType=NRT}
[junit4] 2> 53486 ERROR (closeThreadPool-51-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 53486 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 53486 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 53486 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 53486 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr
[junit4] 2> 53486 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T15:47:43.389852Z
[junit4] 2> 53509 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 53515 INFO (zkConnectionManagerCallback-76-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 53516 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 53656 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 53657 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-2-001/solr.xml
[junit4] 2> 53682 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 54272 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
[junit4] 2> 54295 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@2f0a59f7[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 54295 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@2f0a59f7[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 54335 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@62bc9bca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 54335 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@62bc9bca[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 54379 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62120/solr
[junit4] 2> 54385 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 54387 INFO (zkConnectionManagerCallback-87-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 54388 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 54538 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 54542 INFO (zkConnectionManagerCallback-89-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 54544 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 54730 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 54970 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.ZkController Publish node=127.0.0.1:62139_ as DOWN
[junit4] 2> 55052 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 55052 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62139_
[junit4] 2> 55157 INFO (zkCallback-49-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 55158 INFO (zkCallback-65-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 55164 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 55166 INFO (zkCallback-88-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3)
[junit4] 2> 55274 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 55275 WARN (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] 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> 55353 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 55617 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 55844 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 55845 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 55951 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62139_ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-2-001/cores
[junit4] 2> 56098 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.AbstractFullDistribZkTestBase waitForLiveNode: 127.0.0.1:62139_
[junit4] 2> 56277 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 3 in directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-3-001 of type NRT for shard2
[junit4] 2> 56283 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 56283 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 56283 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 56314 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 56314 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 56314 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms
[junit4] 2> 56325 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@78a55015{/,null,AVAILABLE}
[junit4] 2> 56342 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5f15b0ab{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62143}
[junit4] 2> 56342 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server Started @56467ms
[junit4] 2> 56342 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/tempDir-001/jetty3, hostPort=62143, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-3-001/cores}
[junit4] 2> 56343 ERROR (closeThreadPool-51-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 56343 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 56343 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 56343 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 56343 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr
[junit4] 2> 56343 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T15:47:46.246642Z
[junit4] 2> 56354 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 56454 INFO (zkConnectionManagerCallback-99-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 56455 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 56590 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 56591 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-3-001/solr.xml
[junit4] 2> 56604 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 57130 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
[junit4] 2> 57137 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4de3b73b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 57154 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4de3b73b[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 57168 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@4941016e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 57168 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@4941016e[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 57177 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62120/solr
[junit4] 2> 57180 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 57194 INFO (zkConnectionManagerCallback-110-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 57195 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 57401 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 57402 INFO (zkConnectionManagerCallback-112-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 57409 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 57905 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (3)
[junit4] 2> 58526 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.ZkController Publish node=127.0.0.1:62143_ as DOWN
[junit4] 2> 58566 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 58567 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62143_
[junit4] 2> 58626 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 58645 INFO (zkCallback-88-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 58650 INFO (zkCallback-49-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 58652 INFO (zkCallback-65-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 58667 INFO (zkCallback-111-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4)
[junit4] 2> 58784 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 58786 WARN (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] 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> 58999 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 59076 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 59107 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 59108 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 59111 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62143_ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-3-001/cores
[junit4] 2> 59314 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.AbstractFullDistribZkTestBase waitForLiveNode: 127.0.0.1:62143_
[junit4] 2> 62023 INFO (TEST-TestCustomStream.testDynamicLoadingCustomStream-seed#[E01459883CD27B7F]) [ ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 4 in directory /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-4-001 of type NRT for shard1
[junit4] 2> 62025 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (configured port=0, binding port=0)
[junit4] 2> 62025 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 2 ...
[junit4] 2> 62025 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server jetty-9.4.27.v20200227; built: 2020-02-27T18:37:21.340Z; git: a304fd9f351f337e7c0e2a7c28878dd536149c6c; jvm 14+36
[junit4] 2> 62055 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0
[junit4] 2> 62055 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults
[junit4] 2> 62060 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.session node0 Scavenging every 660000ms
[junit4] 2> 62069 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@3c85c26c{/,null,AVAILABLE}
[junit4] 2> 62078 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@23288d42{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:62147}
[junit4] 2> 62079 INFO (closeThreadPool-51-thread-1) [ ] o.e.j.s.Server Started @62203ms
[junit4] 2> 62079 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/, solrconfig=solrconfig.xml, solr.data.dir=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/tempDir-001/jetty4, hostPort=62147, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-4-001/cores, replicaType=NRT}
[junit4] 2> 62081 ERROR (closeThreadPool-51-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 62081 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory
[junit4] 2> 62081 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0
[junit4] 2> 62082 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 62082 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr
[junit4] 2> 62082 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2020-05-24T15:47:51.985143Z
[junit4] 2> 62084 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 62112 INFO (zkConnectionManagerCallback-122-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 62113 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 62241 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
[junit4] 2> 62241 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-4-001/solr.xml
[junit4] 2> 62260 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e, but no JMX reporters were configured - adding default JMX reporter.
[junit4] 2> 62579 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=false]
[junit4] 2> 62595 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@6c8e4765[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 62596 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@6c8e4765[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 62621 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config Trusting all certificates configured for Client@5a8542e9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 62621 WARN (closeThreadPool-51-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for Client@5a8542e9[provider=null,keyStore=null,trustStore=null]
[junit4] 2> 62624 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:62120/solr
[junit4] 2> 62633 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 62652 INFO (zkConnectionManagerCallback-133-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 62663 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 62906 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 62911 INFO (zkConnectionManagerCallback-135-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected
[junit4] 2> 62915 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 63187 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4)
[junit4] 2> 63492 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.ZkController Publish node=127.0.0.1:62147_ as DOWN
[junit4] 2> 63517 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores
[junit4] 2> 63518 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62147_
[junit4] 2> 63563 INFO (zkCallback-49-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63563 INFO (zkCallback-65-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63588 INFO (zkCallback-88-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63593 INFO (zkCallback-21-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63601 INFO (zkCallback-134-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63602 INFO (zkCallback-111-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (4) -> (5)
[junit4] 2> 63758 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.p.PackageLoader /packages.json updated to version -1
[junit4] 2> 63759 WARN (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] 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> 63888 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 64039 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 64085 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 64104 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@25c2ab9e
[junit4] 2> 64108 INFO (closeThreadPool-51-thread-1) [n:127.0.0.1:62147_ ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J1/temp/solr.core.TestCustomStream_E01459883CD27B7F-001/shard-4-001/cores
[junit4] 2> 64266 INFO (closeThreadPool-51-thread-1) [ ] o.a.s.c.AbstractFullDistribZkTestBase waitForLiveNode: 127.0.0.1:62147_
[junit4] 2> 64295 INFO (qtp1079936242-90) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:62135_&action=ADDREPLICA&collection=collection1&shard=shard2&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 64295 INFO (qtp1079936242-88) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:62143_&action=ADDREPLICA&collection=collection1&shard=shard2&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 64296 INFO (qtp1079936242-91) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:62139_&action=ADDREPLICA&collection=collection1&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 64299 INFO (qtp1079936242-89) [n:127.0.0.1:62124_ ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :addreplica with params node=127.0.0.1:62147_&action=ADDREPLICA&collection=collection1&shard=shard1&type=NRT&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 64512 INFO (qtp1079936242-264) [n:127.0.0.1:62124_ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core.control_collection.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=6
[junit4] 2> 64533 INFO (qt
[...truncated too long message...]
onnector@ee87a76{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1161206 INFO (jetty-closer-9110-thread-2-processing-n:127.0.0.1:53528_solr) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4a1fb68a{/solr,null,UNAVAILABLE}
[junit4] 2> 1161207 INFO (jetty-closer-9110-thread-2-processing-n:127.0.0.1:53528_solr) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1161302 INFO (jetty-closer-9110-thread-1-processing-n:127.0.0.1:53528_solr) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@65661814{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:53528}
[junit4] 2> 1161302 INFO (jetty-closer-9110-thread-1-processing-n:127.0.0.1:53528_solr) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@8e9b812{/solr,null,UNAVAILABLE}
[junit4] 2> 1161302 INFO (jetty-closer-9110-thread-1-processing-n:127.0.0.1:53528_solr) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1161306 INFO (SUITE-CleanupOldIndexTest-seed#[E01459883CD27B7F]-worker) [n:127.0.0.1:53528_solr ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1161519 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> 14 /solr/collections/oldindextest/terms/shard1
[junit4] 2> 4 /solr/aliases.json
[junit4] 2> 4 /solr/clusterprops.json
[junit4] 2> 3 /solr/collections/oldindextest/collectionprops.json
[junit4] 2> 3 /solr/packages.json
[junit4] 2> 3 /solr/security.json
[junit4] 2> 3 /solr/configs/conf1
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 52 /solr/collections/oldindextest/state.json
[junit4] 2> 4 /solr/clusterstate.json
[junit4] 2> 2 /solr/autoscaling.json
[junit4] 2> 2 /solr/collections/oldindextest/leader_elect/shard1/election/72097650116526085-core_node4-n_0000000000
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 28 /solr/overseer/queue
[junit4] 2> 13 /solr/live_nodes
[junit4] 2> 7 /solr/collections
[junit4] 2> 4 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/.scheduled_maintenance
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/overseer/queue-work
[junit4] 2>
[junit4] 2> 1161523 INFO (SUITE-CleanupOldIndexTest-seed#[E01459883CD27B7F]-worker) [n:127.0.0.1:53528_solr ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:53522
[junit4] 2> 1161523 INFO (SUITE-CleanupOldIndexTest-seed#[E01459883CD27B7F]-worker) [n:127.0.0.1:53528_solr ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:53522
[junit4] 2> 1161523 INFO (SUITE-CleanupOldIndexTest-seed#[E01459883CD27B7F]-worker) [n:127.0.0.1:53528_solr ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 53522
[junit4] 2> 1161524 INFO (SUITE-CleanupOldIndexTest-seed#[E01459883CD27B7F]-worker) [n:127.0.0.1:53528_solr ] o.a.s.SolrTestCaseJ4 ------------------------------------------------------- Done waiting for tracked resources to be released
[junit4] 2> May 24, 2020 4:06:11 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> May 24, 2020 4:06:21 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> SEVERE: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CleanupOldIndexTest:
[junit4] 2> 1) Thread[id=13693, name=SessionTracker, state=TIMED_WAITING, group=TGRP-CleanupOldIndexTest]
[junit4] 2> at java.base@14/java.lang.Thread.sleep(Native Method)
[junit4] 2> at app//org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:151)
[junit4] 2> May 24, 2020 4:06:21 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: Starting to interrupt leaked threads:
[junit4] 2> 1) Thread[id=13693, name=SessionTracker, state=TIMED_WAITING, group=TGRP-CleanupOldIndexTest]
[junit4] 2> 1171615 ERROR (SessionTracker) [ ] o.a.z.s.ZooKeeperCriticalThread Severe unrecoverable error, from thread : SessionTracker
[junit4] 2> => java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.base/java.lang.Thread.sleep(Native Method)
[junit4] 2> java.lang.InterruptedException: sleep interrupted
[junit4] 2> at java.lang.Thread.sleep(Native Method) [?:?]
[junit4] 2> at org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:151) ~[zookeeper-3.5.7.jar:3.5.7]
[junit4] 2> May 24, 2020 4:06:21 PM com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
[junit4] 2> INFO: All leaked threads terminated.
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86): {rnd_b=BlockTreeOrds(blocksize=128), a_t=PostingsFormat(name=MockRandom), _root_=PostingsFormat(name=Direct), id=BlockTreeOrds(blocksize=128)}, docValues:{}, maxPointsInLeafNode=1137, maxMBSortInHeap=5.259801401078608, sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@7e0d2893), locale=sah, timezone=Africa/Mogadishu
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 14 (64-bit)/cpus=6,threads=1,free=268435456,total=536870912
[junit4] 2> NOTE: All tests run in this JVM: [TestJmxIntegration, TestComponentsName, NestedAtomicUpdateTest, SubstringBytesRefFilterTest, HighlighterTest, SpatialHeatmapFacetsTest, TestExpandComponent, JSONWriterTest, PreAnalyzedFieldManagedSchemaCloudTest, TestDefaultStatsCache, DistributedSpellCheckComponentTest, SuggestComponentTest, RuleEngineTest, SolrShardReporterTest, IndexSizeTriggerMixedBoundsTest, SearchHandlerTest, StatsReloadRaceTest, DocExpirationUpdateProcessorFactoryTest, TestOmitPositions, SolrXmlInZkTest, TestCoreAdminApis, AutoScalingHandlerTest, ConcurrentCreateCollectionTest, TestDocBasedVersionConstraints, TestSortableTextField, TestScoreJoinQPNoScore, TestConfigReload, ClassificationUpdateProcessorTest, ZkFailoverTest, TestDynamicLoadingUrl, TestInPlaceUpdatesStandalone, HdfsNNFailoverTest, TestFreeTextSuggestions, LargeFieldTest, TestFieldCacheVsDocValues, TestRawResponseWriter, TestNonDefinedSimilarityFactory, TestSimDistributedQueue, AliasIntegrationTest, TestSolrCoreProperties, BlockDirectoryTest, TestHighlightDedupGrouping, TestSerializedLuceneMatchVersion, TestDFRSimilarityFactory, TestFieldSortValues, MetricsConfigTest, MetricsHistoryWithAuthIntegrationTest, SampleTest, TestExceedMaxTermLength, SecurityConfHandlerTest, CurrencyFieldTypeTest, TimeZoneUtilsTest, TestCloudPivotFacet, SearchRateTriggerTest, OutOfBoxZkACLAndCredentialsProvidersTest, HDFSCollectionsAPITest, TestFieldTypeResource, TestCoreDiscovery, AtomicUpdateRemovalJavabinTest, RollingRestartTest, JavabinLoaderTest, NodeAddedTriggerIntegrationTest, MoveReplicaTest, TestRTGBase, TestUninvertingReader, RemoteQueryErrorTest, ManagedSchemaRoundRobinCloudTest, SolrCmdDistributorTest, AsyncCallRequestStatusResponseTest, DistributedFacetExistsSmallTest, TestStressUserVersions, TestSimNodeAddedTrigger, HdfsThreadLeakTest, TestStressLiveNodes, CleanupOldIndexTest]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CleanupOldIndexTest -Dtests.seed=E01459883CD27B7F -Dtests.slow=true -Dtests.locale=sah -Dtests.timezone=Africa/Mogadishu -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J4 | CleanupOldIndexTest (suite) <<<
[junit4] > Throwable #1: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.cloud.CleanupOldIndexTest:
[junit4] > 1) Thread[id=13693, name=SessionTracker, state=TIMED_WAITING, group=TGRP-CleanupOldIndexTest]
[junit4] > at java.base@14/java.lang.Thread.sleep(Native Method)
[junit4] > at app//org.apache.zookeeper.server.SessionTrackerImpl.run(SessionTrackerImpl.java:151)
[junit4] > at __randomizedtesting.SeedInfo.seed([E01459883CD27B7F]:0)
[junit4] Completed [380/913 (2!)] on J4 in 28.35s, 1 test, 1 error <<< FAILURES!
[...truncated 46702 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6064/consoleText
[repro] Revision: 675956c0041b18d48a7c059ea458c49f5310d74a
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC"
[repro] Repro line: ant test -Dtestcase=TestCustomStream -Dtests.method=testDynamicLoadingCustomStream -Dtests.seed=E01459883CD27B7F -Dtests.slow=true -Dtests.locale=sw -Dtests.timezone=America/Jujuy -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] Repro line: ant test -Dtestcase=CleanupOldIndexTest -Dtests.seed=E01459883CD27B7F -Dtests.slow=true -Dtests.locale=sah -Dtests.timezone=Africa/Mogadishu -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestCustomStream
[repro] CleanupOldIndexTest
[repro] ant compile-test
[...truncated 3158 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=10 -Dtests.class="*.TestCustomStream|*.CleanupOldIndexTest" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UnlockExperimentalVMOptions -XX:+UseZGC" -Dtests.seed=E01459883CD27B7F -Dtests.slow=true -Dtests.locale=sw -Dtests.timezone=America/Jujuy -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[...truncated 104 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.CleanupOldIndexTest
[repro] 0/5 failed: org.apache.solr.core.TestCustomStream
[repro] Exiting with code 0
[...truncated 73 lines...]
[JENKINS] Lucene-Solr-master-MacOSX (64bit/jdk-11.0.6) - Build #
6065 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6065/
Java: 64bit/jdk-11.0.6 -XX:-UseCompressedOops -XX:+UseParallelGC
3 tests failed.
FAILED: org.apache.solr.cloud.autoscaling.NodeLostTriggerIntegrationTest.testNodeLostTrigger
Error Message:
The trigger did not fire at all
Stack Trace:
java.lang.AssertionError: The trigger did not fire at all
at __randomizedtesting.SeedInfo.seed([3E1E65615723D156:3AE0CC736DE953CC]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.assertTrue(Assert.java:41)
at org.apache.solr.cloud.autoscaling.NodeLostTriggerIntegrationTest.testNodeLostTrigger(NodeLostTriggerIntegrationTest.java:275)
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)
FAILED: org.apache.solr.cloud.autoscaling.sim.TestSimScenario.testSuggestions
Error Message:
expected:<[9]> but was:<[3]>
Stack Trace:
org.junit.ComparisonFailure: expected:<[9]> but was:<[3]>
at __randomizedtesting.SeedInfo.seed([3E1E65615723D156:98C25C94991786A8]:0)
at org.junit.Assert.assertEquals(Assert.java:115)
at org.junit.Assert.assertEquals(Assert.java:144)
at org.apache.solr.cloud.autoscaling.sim.TestSimScenario.testSuggestions(TestSimScenario.java:115)
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)
FAILED: org.apache.solr.update.processor.TestNamedUpdateProcessors.test
Error Message:
{ "responseHeader":{ "status":500, "QTime":30128}, "errorMessages":["4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]\n"], "WARNING":"This response format is experimental. It is likely to change in the future.", "error":{ "metadata":[ "error-class","org.apache.solr.common.SolrException", "root-error-class","org.apache.solr.common.SolrException"], "msg":"4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]", "trace":"org.apache.solr.common.SolrException: 4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]\n\tat org.apache.solr.handler.SolrConfigHandler.waitForAllReplicasState(SolrConfigHandler.java:821)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handleCommands(SolrConfigHandler.java:528)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handlePOST(SolrConfigHandler.java:365)\n\tat org.apache.solr.handler.SolrConfigHandler.handleRequestBody(SolrConfigHandler.java:139)\n\tat org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:209)\n\tat org.apache.solr.core.SolrCore.execute(SolrCore.java:2591)\n\tat org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:803)\n\tat org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:582)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:415)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)\n\tat org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)\n\tat org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)\n\tat org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.server.Server.handle(Server.java:500)\n\tat org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)\n\tat org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)\n\tat org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)\n\tat org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)\n\tat org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)\n\tat org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)\n\tat org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)\n\tat java.base/java.lang.Thread.run(Thread.java:834)\n", "code":500}} expected null, but was:<[4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/] ]>
Stack Trace:
java.lang.AssertionError: {
"responseHeader":{
"status":500,
"QTime":30128},
"errorMessages":["4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]\n"],
"WARNING":"This response format is experimental. It is likely to change in the future.",
"error":{
"metadata":[
"error-class","org.apache.solr.common.SolrException",
"root-error-class","org.apache.solr.common.SolrException"],
"msg":"4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]",
"trace":"org.apache.solr.common.SolrException: 4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]\n\tat org.apache.solr.handler.SolrConfigHandler.waitForAllReplicasState(SolrConfigHandler.java:821)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handleCommands(SolrConfigHandler.java:528)\n\tat org.apache.solr.handler.SolrConfigHandler$Command.handlePOST(SolrConfigHandler.java:365)\n\tat org.apache.solr.handler.SolrConfigHandler.handleRequestBody(SolrConfigHandler.java:139)\n\tat org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:209)\n\tat org.apache.solr.core.SolrCore.execute(SolrCore.java:2591)\n\tat org.apache.solr.servlet.HttpSolrCall.execute(HttpSolrCall.java:803)\n\tat org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:582)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:415)\n\tat org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:345)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:166)\n\tat org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1604)\n\tat org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:545)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1610)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1300)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)\n\tat org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:485)\n\tat org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1580)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)\n\tat org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1215)\n\tat org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.rewrite.handler.RewriteHandler.handle(RewriteHandler.java:322)\n\tat org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:717)\n\tat org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)\n\tat org.eclipse.jetty.server.Server.handle(Server.java:500)\n\tat org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)\n\tat org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)\n\tat org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)\n\tat org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)\n\tat org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)\n\tat org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)\n\tat org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)\n\tat org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)\n\tat java.base/java.lang.Thread.run(Thread.java:834)\n",
"code":500}}
expected null, but was:<[4 out of 5 the property overlay to be of version 1 within 30 seconds! Failed cores: [http://127.0.0.1:57493/collection1_shard2_replica_n1/, http://127.0.0.1:57502/collection1_shard2_replica_n5/, http://127.0.0.1:57506/collection1_shard1_replica_n2/, http://127.0.0.1:57498/collection1_shard1_replica_n7/]
]>
at __randomizedtesting.SeedInfo.seed([3E1E65615723D156:B64A5ABBF9DFBCAE]:0)
at org.junit.Assert.fail(Assert.java:88)
at org.junit.Assert.failNotNull(Assert.java:755)
at org.junit.Assert.assertNull(Assert.java:737)
at org.apache.solr.core.TestSolrConfigHandler.runConfigCommand(TestSolrConfigHandler.java:179)
at org.apache.solr.update.processor.TestNamedUpdateProcessors.test(TestNamedUpdateProcessors.java:81)
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:1081)
at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:1053)
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 13756 lines...]
[junit4] Suite: org.apache.solr.cloud.autoscaling.sim.TestSimScenario
[junit4] 2> 534947 INFO (SUITE-TestSimScenario-seed#[3E1E65615723D156]-worker) [ ] o.a.s.SolrTestCase Setting 'solr.default.confdir' system property to test-framework derived value of '/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/server/solr/configsets/_default/conf'
[junit4] 2> 534947 INFO (SUITE-TestSimScenario-seed#[3E1E65615723D156]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
[junit4] 2> 534950 INFO (SUITE-TestSimScenario-seed#[3E1E65615723D156]-worker) [ ] o.a.s.SolrTestCaseJ4 Created dataDir: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestSimScenario_3E1E65615723D156-001/data-dir-65-001
[junit4] 2> 534951 INFO (SUITE-TestSimScenario-seed#[3E1E65615723D156]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false
[junit4] 2> 534952 INFO (SUITE-TestSimScenario-seed#[3E1E65615723D156]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, clientAuth=0.0/0.0) w/ MAC_OS_X supressed clientAuth
[junit4] 2> 534956 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testAutoAddReplicas
[junit4] 2> 534994 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=2
[junit4] 2> 534997 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=2
[junit4] 2> 535005 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.SolrPaths solr home defaulted to 'solr/' (could not find system property or JNDI)
[junit4] 2> 535046 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 535047 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 535047 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 535047 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10000_solr
[junit4] 2> 535047 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 535048 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10000_solr]
[junit4] 2> 535049 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 535049 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 535049 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535063 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 535064 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy'+:+[{'replica'+:+'<3',+'shard'+:+'#EACH',+'collection'+:+'testCollection','node':'#ANY'}]}&defaultWaitFor=10
[junit4] 2> 535064 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy'+:+[{'replica'+:+'<3',+'shard'+:+'#EACH',+'collection'+:+'testCollection','node':'#ANY'}]}&defaultWaitFor=10
[junit4] 2> 535068 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 535069 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 535070 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 535071 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10001_solr, 127.0.0.1:10000_solr]
[junit4] 2> 535071 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 535071 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 535072 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 535072 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 535074 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535095 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535096 DEBUG (simCloudManagerPool-4133-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection
[junit4] 2> 535139 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535160 DEBUG (ScheduledTrigger-4134-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535205 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535247 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535285 DEBUG (ScheduledTrigger-4134-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535326 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535363 DEBUG (ScheduledTrigger-4134-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535398 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535426 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535500 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535518 DEBUG (simCloudManagerPool-4133-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 535523 DEBUG (simCloudManagerPool-4133-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=2): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 535538 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535571 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535578 DEBUG (simCloudManagerPool-4133-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 535578 DEBUG (simCloudManagerPool-4133-thread-5) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=4): {"core_node4":{
[junit4] 2> "core":"testCollection_shard2_replica_n4",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 535583 DEBUG (simCloudManagerPool-4133-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection
[junit4] 2> 535591 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 535591 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 535596 DEBUG (ScheduledTrigger-4134-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 535614 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 5. SetEventListener trigger=.auto_add_replicas&stage=SUCCEEDED
[junit4] 2> 535614 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario SetEventListener trigger=.auto_add_replicas&stage=SUCCEEDED
[junit4] 2> 535615 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 6. KillNodes node=${_random_node_}
[junit4] 2> 535615 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario KillNodes node=127.0.0.1:10001_solr
[junit4] 2> 535616 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimClusterStateProvider -- created marker: /autoscaling/nodeLost/127.0.0.1:10001_solr
[junit4] 2> 535626 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 2
[junit4] 2> 535626 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Tracking lost node: 127.0.0.1:10001_solr
[junit4] 2> 535629 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 7. WaitEvent trigger=.auto_add_replicas&wait=60
[junit4] 2> 535629 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario WaitEvent trigger=.auto_add_replicas&wait=60
[junit4] 2> 535649 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535688 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535712 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535785 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535818 DEBUG (ScheduledTrigger-4134-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535840 DEBUG (ScheduledTrigger-4134-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 535840 DEBUG (ScheduledTrigger-4134-thread-4) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger firing registered processor for lost nodes: [127.0.0.1:10001_solr]
[junit4] 2> 535843 DEBUG (ScheduledTrigger-4134-thread-4) [ ] o.a.s.c.a.ScheduledTriggers ++++++++ Cooldown inactive - processing event: {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 535855 DEBUG (ScheduledTrigger-4134-thread-4) [ ] o.a.s.c.a.ScheduledTriggers Pausing all triggers: [.auto_add_replicas, .scheduled_maintenance]
[junit4] 2> 535901 DEBUG (ScheduledTrigger-4134-thread-4) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":627219919778504,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 535904 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing actions for {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":627219919778504,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 535907 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ComputePlanAction -- processing event: {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":627219919778504,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {BEFORE_ACTION=[auto_add_replicas_plan]}
[junit4] 2> 535917 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 535919 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ComputePlanAction Computed Plan: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 535919 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ExecutePlanAction -- processing event: {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":627219919778504,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}} with context properties: {operations=[{
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"MOVEREPLICA",
[junit4] 2> "params.collection":"testCollection",
[junit4] 2> "params.targetNode":"127.0.0.1:10000_solr",
[junit4] 2> "params.inPlaceMove":"true",
[junit4] 2> "params.replica":"core_node2"}, {
[junit4] 2> "class":"org.apache.solr.client.solrj.request.CollectionAdminRequest$MoveReplica",
[junit4] 2> "method":"GET",
[junit4] 2> "params.action":"MOVEREPLICA",
[junit4] 2> "params.collection":"testCollection",
[junit4] 2> "params.targetNode":"127.0.0.1:10000_solr",
[junit4] 2> "params.inPlaceMove":"true",
[junit4] 2> "params.replica":"core_node3"}], AFTER_ACTION=[auto_add_replicas_plan], BEFORE_ACTION=[auto_add_replicas_plan, execute_plan]}
[junit4] 2> 535920 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node2
[junit4] 2> 536076 DEBUG (simCloudManagerPool-4133-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node6":{
[junit4] 2> "core":"testCollection_shard1_replica_n5",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"down",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 536330 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ExecutePlanAction Executing operation: action=MOVEREPLICA&collection=testCollection&targetNode=127.0.0.1:10000_solr&inPlaceMove=true&replica=core_node3
[junit4] 2> 536470 DEBUG (simCloudManagerPool-4133-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node8":{
[junit4] 2> "core":"testCollection_shard2_replica_n7",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10000_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"down",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 536594 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.SystemLogListener Collection .system missing, skip sending event {
[junit4] 2> "id":"23a71590b5b14Tbgoblj7od4s34neba64zhjfzq",
[junit4] 2> "source":".auto_add_replicas",
[junit4] 2> "eventTime":627208453053204,
[junit4] 2> "eventType":"NODELOST",
[junit4] 2> "properties":{
[junit4] 2> "eventTimes":[627208453053204],
[junit4] 2> "preferredOperation":"movereplica",
[junit4] 2> "_enqueue_time_":627219919778504,
[junit4] 2> "nodeNames":["127.0.0.1:10001_solr"]}}
[junit4] 2> 536595 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 8. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 536595 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .auto_add_replicas after 100ms
[junit4] 2> 536595 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 536595 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers Resuming trigger: .scheduled_maintenance after 100ms
[junit4] 2> 536595 DEBUG (AutoscalingActionExecutor-4135-thread-1) [ ] o.a.s.c.a.ScheduledTriggers -- processing took 34552 ms for event id=23a71590b5b14Tbgoblj7od4s34neba64zhjfzq
[junit4] 2> 536595 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 9. SaveSnapshot path=${snapshotPath}
[junit4] 2> 536596 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario SaveSnapshot path=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestSimScenario_3E1E65615723D156-001/tempDir-001/snapshot
[junit4] 2> 536606 WARN (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimUtils V2 action SET_CLUSTER_PROPERTY_OBJ has no equivalent V1 action
[junit4] 2> 536606 WARN (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimUtils V2 action GET_NODES has no equivalent V1 action
[junit4] 2> 536618 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 23 resources from SimDistribStateManager
[junit4] 2> 536700 DEBUG (ScheduledTrigger-4134-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 536709 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 536717 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 536740 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 536743 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 536743 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 536743 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 536743 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 536782 DEBUG (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - loaded snapshot of 23 resources
[junit4] 2> 536790 INFO (TEST-TestSimScenario.testAutoAddReplicas-seed#[3E1E65615723D156]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testAutoAddReplicas
[junit4] 2> 536805 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSuggestions
[junit4] 2> 536808 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=2
[junit4] 2> 536808 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=2
[junit4] 2> 536812 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10002_solr
[junit4] 2> 536812 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 536813 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 536813 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 536813 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 536814 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10002_solr]
[junit4] 2> 536814 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 536814 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 536814 DEBUG (ScheduledTrigger-4140-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 536818 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 536821 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 536821 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 536822 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 536827 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 536827 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 536827 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 536827 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 536827 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 536841 DEBUG (simCloudManagerPool-4139-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection
[junit4] 2> 536841 DEBUG (ScheduledTrigger-4140-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 536863 DEBUG (ScheduledTrigger-4140-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536871 DEBUG (simCloudManagerPool-4139-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 536871 DEBUG (simCloudManagerPool-4139-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=2): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 536883 DEBUG (ScheduledTrigger-4140-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536899 DEBUG (simCloudManagerPool-4139-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 536899 DEBUG (simCloudManagerPool-4139-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=4): {"core_node3":{
[junit4] 2> "core":"testCollection_shard2_replica_n3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10002_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 536901 DEBUG (simCloudManagerPool-4139-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection
[junit4] 2> 536902 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 536902 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 536904 DEBUG (ScheduledTrigger-4140-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536924 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 5. CtxSet key=myNode&value=${_random_node_}
[junit4] 2> 536924 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario CtxSet key=myNode&value=127.0.0.1:10002_solr
[junit4] 2> 536924 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 6. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 536924 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10002_solr
[junit4] 2> 536924 DEBUG (ScheduledTrigger-4140-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536928 INFO (simCloudManagerPool-4139-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10002_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 536928 INFO (simCloudManagerPool-4139-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 536940 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 7. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 536940 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10002_solr
[junit4] 2> 536944 INFO (simCloudManagerPool-4139-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10002_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 536944 INFO (simCloudManagerPool-4139-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 536945 DEBUG (ScheduledTrigger-4140-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536972 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 8. LoopOp iterations=${iterative}
[junit4] 2> 536972 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=0
[junit4] 2> 536972 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 9. LoopOp iterations=${justCalc}
[junit4] 2> 536972 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=1
[junit4] 2> 536973 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario * iter 1 :
[junit4] 2> 536973 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 536974 DEBUG (ScheduledTrigger-4140-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 536996 DEBUG (ScheduledTrigger-4140-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537016 DEBUG (ScheduledTrigger-4140-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537042 DEBUG (ScheduledTrigger-4140-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537044 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 537044 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - SaveSnapshot path=/Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.sim.TestSimScenario_3E1E65615723D156-001/tempDir-002/snapshot/0)
[junit4] 2> 537046 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 22 resources from SimDistribStateManager
[junit4] 2> 537058 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 10. Dump redact=true
[junit4] 2> 537062 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario Dump redact=true
[junit4] 2> 537063 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 22 resources from SimDistribStateManager
[junit4] 2> 537064 DEBUG (ScheduledTrigger-4140-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537084 INFO (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread woken up but we are closed, exiting.
[junit4] 2> 537085 DEBUG (ScheduledTrigger-4140-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537087 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down scheduled thread pool executor now
[junit4] 2> 537107 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Shutting down action executor now
[junit4] 2> 537115 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for action executor
[junit4] 2> 537115 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers Awaiting termination for scheduled thread pool executor
[junit4] 2> 537115 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.ScheduledTriggers ScheduledTriggers closed completely
[junit4] 2> 537115 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.OverseerTriggerThread OverseerTriggerThread has been closed explicitly
[junit4] 2> 537115 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 1. CreateCluster numNodes=2
[junit4] 2> 537115 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario CreateCluster numNodes=2
[junit4] 2> 537121 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimClusterStateProvider --- new Overseer leader: 127.0.0.1:10004_solr
[junit4] 2> 537121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers
[junit4] 2> 537121 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1
[junit4] 2> 537122 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0
[junit4] 2> 537122 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1
[junit4] 2> 537124 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:10004_solr]
[junit4] 2> 537125 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 537125 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1
[junit4] 2> 537125 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 1 and last live nodes: 1
[junit4] 2> 537128 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory.
[junit4] 2> 537134 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 2. LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 537134 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoadAutoscaling json={'cluster-policy':[]}
[junit4] 2> 537135 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 2
[junit4] 2> 537137 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 2
[junit4] 2> 537137 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread -- deactivating old nodeLost / nodeAdded markers
[junit4] 2> 537137 DEBUG (Simulated OverseerAutoScalingTriggerThread) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 2, lastZnodeVersion 2
[junit4] 2> 537145 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 3. RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 537145 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=CREATE&autoAddReplicas=true&name=testCollection&numShards=2&replicationFactor=2&maxShardsPerNode=2
[junit4] 2> 537146 DEBUG (simCloudManagerPool-4145-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- simCreateCollection testCollection
[junit4] 2> 537157 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 1
[junit4] 2> 537177 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537181 DEBUG (simCloudManagerPool-4145-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard1)
[junit4] 2> 537181 DEBUG (simCloudManagerPool-4145-thread-2) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard1 (currentVersion=2): {"core_node1":{
[junit4] 2> "core":"testCollection_shard1_replica_n1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 537193 DEBUG (simCloudManagerPool-4145-thread-1) [ ] o.a.s.c.a.s.SimClusterStateProvider -- finished createCollection testCollection
[junit4] 2> 537196 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 4. WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 537196 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario WaitCollection collection=testCollection&shards=2&replicas=2
[junit4] 2> 537200 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537209 DEBUG (simCloudManagerPool-4145-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider Running leader election (testCollection / shard2)
[junit4] 2> 537209 DEBUG (simCloudManagerPool-4145-thread-4) [ ] o.a.s.c.a.s.SimClusterStateProvider -- elected new leader for testCollection / shard2 (currentVersion=4): {"core_node3":{
[junit4] 2> "core":"testCollection_shard2_replica_n3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10004_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 537221 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537221 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 5. CtxSet key=myNode&value=${_random_node_}
[junit4] 2> 537221 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario CtxSet key=myNode&value=127.0.0.1:10004_solr
[junit4] 2> 537221 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 6. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 537221 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr
[junit4] 2> 537223 INFO (simCloudManagerPool-4145-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 537223 INFO (simCloudManagerPool-4145-thread-6) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 537234 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 7. RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=${myNode}
[junit4] 2> 537234 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr
[junit4] 2> 537237 INFO (simCloudManagerPool-4145-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 537237 INFO (simCloudManagerPool-4145-thread-7) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 537243 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537249 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 8. LoopOp iterations=${iterative}
[junit4] 2> 537249 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=10
[junit4] 2> 537249 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario * iter 1 :
[junit4] 2> 537249 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 537262 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 537262 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - ApplySuggestions )
[junit4] 2> 537265 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537286 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537307 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537329 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537357 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537377 DEBUG (simCloudManagerPool-4145-thread-8) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node10":{
[junit4] 2> "core":"testCollection_shard2_replica_n9",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 537382 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537406 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537441 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537480 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537511 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537536 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537537 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 537542 INFO (simCloudManagerPool-4145-thread-9) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 537542 INFO (simCloudManagerPool-4145-thread-9) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 537577 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537586 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 537629 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537633 INFO (simCloudManagerPool-4145-thread-10) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 537634 INFO (simCloudManagerPool-4145-thread-10) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 537662 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537677 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario * iter 2 :
[junit4] 2> 537678 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 537709 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537721 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 537721 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - ApplySuggestions )
[junit4] 2> 537744 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537786 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537837 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537837 DEBUG (simCloudManagerPool-4145-thread-11) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node16":{
[junit4] 2> "core":"testCollection_shard1_replica_n15",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "leader":"true",
[junit4] 2> "SEARCHER.searcher.maxDoc":0,
[junit4] 2> "SEARCHER.searcher.deletedDocs":0,
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6,
[junit4] 2> "SEARCHER.searcher.numDocs":0}}
[junit4] 2> 537862 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537886 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537906 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537929 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537952 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 537955 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 537976 INFO (simCloudManagerPool-4145-thread-12) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 537976 INFO (simCloudManagerPool-4145-thread-12) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 537981 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538009 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538010 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 538030 INFO (simCloudManagerPool-4145-thread-13) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 538030 INFO (simCloudManagerPool-4145-thread-13) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 538034 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538053 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario * iter 3 :
[junit4] 2> 538053 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 538071 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538091 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - 1 suggestions
[junit4] 2> 538092 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - ApplySuggestions )
[junit4] 2> 538125 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538152 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538176 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538205 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538240 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538286 DEBUG (ScheduledTrigger-4146-thread-4) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538288 DEBUG (simCloudManagerPool-4145-thread-14) [ ] o.a.s.c.a.s.SimClusterStateProvider -- new replica: {"core_node22":{
[junit4] 2> "core":"testCollection_shard1_replica_n21",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"testCollection",
[junit4] 2> "node_name":"127.0.0.1:10005_solr",
[junit4] 2> "type":"NRT",
[junit4] 2> "path":"/admin/collections",
[junit4] 2> "node":"127.0.0.1:10004_solr",
[junit4] 2> "INDEX.sizeInBytes":10240,
[junit4] 2> "action":"ADDREPLICA",
[junit4] 2> "createNodeSet":"127.0.0.1:10004_solr",
[junit4] 2> "state":"active",
[junit4] 2> "INDEX.sizeInGB":9.5367431640625E-6}}
[junit4] 2> 538314 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538339 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538376 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538399 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538428 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538429 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 538462 INFO (simCloudManagerPool-4145-thread-15) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 538462 INFO (simCloudManagerPool-4145-thread-15) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 538465 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538489 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - RunSolrRequest path=/admin/collections&action=ADDREPLICA&collection=testCollection&shard=shard1&node=127.0.0.1:10004_solr)
[junit4] 2> 538499 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538513 INFO (simCloudManagerPool-4145-thread-16) [ ] o.a.s.c.a.c.AddReplicaCmd Node Identified 127.0.0.1:10004_solr for creating new replica of shard shard1 for collection testCollection
[junit4] 2> 538513 INFO (simCloudManagerPool-4145-thread-16) [ ] o.a.s.c.a.c.AddReplicaCmd Returning CreateReplica command.
[junit4] 2> 538549 DEBUG (ScheduledTrigger-4146-thread-3) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538553 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario * iter 4 :
[junit4] 2> 538553 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - CalculateSuggestions )
[junit4] 2> 538758 DEBUG (ScheduledTrigger-4146-thread-1) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538789 DEBUG (ScheduledTrigger-4146-thread-2) [ ] o.a.s.c.a.NodeLostTrigger Running NodeLostTrigger: .auto_add_replicas with currently live nodes: 2 and last live nodes: 2
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario - 0 suggestions
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario -- abortLoop requested, aborting after 3 iterations.
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 9. LoopOp iterations=${justCalc}
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario LoopOp iterations=0
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario 10. Dump redact=true
[junit4] 2> 538794 INFO (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SimScenario Dump redact=true
[junit4] 2> 538795 DEBUG (TEST-TestSimScenario.testSuggestions-seed#[3E1E65615723D156]) [ ] o.a.s.c.a.s.SnapshotDistribStateManager - copying 22 resources from SimDistribStateManager
[junit4] 2> {"autoscalingState":{"suggestions":[{
[junit4] 2> "suggestion":{
[junit4] 2> "type":"improvement",
[junit4] 2> "operation":{
[junit4] 2> "method":"POST",
[junit4] 2> "path":"/c/COLL_0",
[junit4] 2> "command":{"move-replica":{
[junit4] 2> "targetNode":"N_3_solr",
[junit4] 2> "inPlaceMove":"true",
[junit4] 2> "replica":"core_node8"}}}},
[junit4] 2> "replica":{"core_node8":{
[junit4] 2> "core":"COLL_0_shard1_replica_n7",
[junit4] 2>
[...truncated too long message...]
loser-11487-thread-2) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@187a503c{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1847610 INFO (jetty-closer-11487-thread-2) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@319a197e{/solr,null,UNAVAILABLE}
[junit4] 2> 1847610 INFO (jetty-closer-11487-thread-2) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1847712 INFO (jetty-closer-11487-thread-3) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@19c62e9{HTTP/1.1, (http/1.1, h2c)}{127.0.0.1:0}
[junit4] 2> 1847712 INFO (jetty-closer-11487-thread-3) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@4d99860e{/solr,null,UNAVAILABLE}
[junit4] 2> 1847712 INFO (jetty-closer-11487-thread-3) [ ] o.e.j.s.session node0 Stopped scavenging
[junit4] 2> 1847713 INFO (TEST-NodeLostTriggerIntegrationTest.testNodeLostTrigger-seed#[3E1E65615723D156]) [ ] o.a.s.c.ZkTestServer Shutting down ZkTestServer.
[junit4] 2> 1847920 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> 5 /solr/aliases.json
[junit4] 2> 5 /solr/clusterprops.json
[junit4] 2> 4 /solr/packages.json
[junit4] 2> 4 /solr/security.json
[junit4] 2>
[junit4] 2> Maximum concurrent data watches above limit:
[junit4] 2>
[junit4] 2> 5 /solr/clusterstate.json
[junit4] 2> 4 /solr/autoscaling.json
[junit4] 2>
[junit4] 2> Maximum concurrent children watches above limit:
[junit4] 2>
[junit4] 2> 15 /solr/live_nodes
[junit4] 2> 7 /solr/overseer/queue
[junit4] 2> 5 /solr/collections
[junit4] 2> 5 /solr/overseer/collection-queue-work
[junit4] 2> 2 /solr/autoscaling/events/.auto_add_replicas
[junit4] 2> 2 /solr/autoscaling/events/node_lost_trigger
[junit4] 2>
[junit4] 2> 1847924 INFO (TEST-NodeLostTriggerIntegrationTest.testNodeLostTrigger-seed#[3E1E65615723D156]) [ ] o.a.s.c.ZkTestServer waitForServerDown: 127.0.0.1:52206
[junit4] 2> 1847924 INFO (TEST-NodeLostTriggerIntegrationTest.testNodeLostTrigger-seed#[3E1E65615723D156]) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:52206
[junit4] 2> 1847924 INFO (TEST-NodeLostTriggerIntegrationTest.testNodeLostTrigger-seed#[3E1E65615723D156]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 52206
[junit4] 2> 1847925 INFO (TEST-NodeLostTriggerIntegrationTest.testNodeLostTrigger-seed#[3E1E65615723D156]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testNodeLostTrigger
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=NodeLostTriggerIntegrationTest -Dtests.method=testNodeLostTrigger -Dtests.seed=3E1E65615723D156 -Dtests.slow=true -Dtests.locale=lv -Dtests.timezone=Australia/Hobart -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 24.7s J2 | NodeLostTriggerIntegrationTest.testNodeLostTrigger <<<
[junit4] > Throwable #1: java.lang.AssertionError: The trigger did not fire at all
[junit4] > at __randomizedtesting.SeedInfo.seed([3E1E65615723D156:3AE0CC736DE953CC]:0)
[junit4] > at org.apache.solr.cloud.autoscaling.NodeLostTriggerIntegrationTest.testNodeLostTrigger(NodeLostTriggerIntegrationTest.java:275)
[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: /Users/jenkins/workspace/Lucene-Solr-master-MacOSX/solr/build/solr-core/test/J2/temp/solr.cloud.autoscaling.NodeLostTriggerIntegrationTest_3E1E65615723D156-001
[junit4] 2> May 24, 2020 8:53:56 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene86), sim=Asserting(org.apache.lucene.search.similarities.AssertingSimilarity@567ddeb2), locale=lv, timezone=Australia/Hobart
[junit4] 2> NOTE: Mac OS X 10.14.6 x86_64/AdoptOpenJDK 11.0.6 (64-bit)/cpus=6,threads=1,free=213334904,total=476053504
[junit4] 2> NOTE: All tests run in this JVM: [SaslZkACLProviderTest, CheckHdfsIndexTest, SortSpecParsingTest, ZkSolrClientTest, SolrSlf4jReporterTest, TestCollectionsAPIViaSolrCloudCluster, StatelessScriptUpdateProcessorFactoryTest, MetricsHistoryHandlerTest, TestTestInjection, CdcrBidirectionalTest, HdfsCollectionsAPIDistributedZkTest, OverseerModifyCollectionTest, DimensionalRoutedAliasUpdateProcessorTest, CursorMarkTest, TestDocumentBuilder, TestTermsQParserPlugin, ConcurrentCreateRoutedAliasTest, TestIntervalFaceting, QueryParsingTest, HLLUtilTest, SolrPluginUtilsTest, TestLockTree, TestReRankQParserPlugin, TestImpersonationWithHadoopAuth, AddSchemaFieldsUpdateProcessorFactoryTest, TestSQLHandler, TestSimGenericDistributedQueue, ActionThrottleTest, TestBulkSchemaAPI, PeerSyncTest, MinimalSchemaTest, UpdateRequestProcessorFactoryTest, TestComplexPhraseLeadingWildcard, TestCollectionAPIs, TestPhraseSuggestions, TestNRTOpen, RootFieldTest, HttpSolrCallGetCoreTest, TestOrdValues, HdfsAutoAddReplicasIntegrationTest, TestLogWatcher, DocValuesMissingTest, TestSolrXml, IgnoreLargeDocumentProcessorFactoryTest, TestUseDocValuesAsStored2, SolrCLIZkUtilsTest, TestQueryTypes, TestUpdate, AdminHandlersProxyTest, SpellPossibilityIteratorTest, TestTrie, TestExactStatsCache, DistributedFacetPivotSmallAdvancedTest, TestConfigSets, OpenExchangeRatesOrgProviderTest, TestBlendedInfixSuggestions, TestLuceneMatchVersion, CdcrUpdateLogTest, TimeRoutedAliasUpdateProcessorTest, TestMacroExpander, HighlighterConfigTest, JsonLoaderTest, TestLegacyNumericRangeQueryBuilder, NestedShardedAtomicUpdateTest, BasicAuthOnSingleNodeTest, SOLR749Test, DistributedFacetSimpleRefinementLongTailTest, RegexBoostProcessorTest, TestConfigSetsAPIZkFailure, TestSimScenario, LeaderElectionTest, SolrIndexSplitterTest, OrderedExecutorTest, ResponseBuilderTest, SuggesterTSTTest, TestSweetSpotSimilarityFactory, TestElisionMultitermQuery, FacetPivotSmallTest, HdfsLockFactoryTest, DeleteStatusTest, TestRebalanceLeaders, TestCSVResponseWriter, TestStressCloudBlindAtomicUpdates, TestDirectoryFactory, ZkStateWriterTest, TestLMJelinekMercerSimilarityFactory, TestSchemaManager, ConvertedLegacyTest, SolrMetricReporterTest, CdcrVersionReplicationTest, ZkCLITest, SolrInfoBeanTest, SolrTestCaseJ4Test, TestCrossCoreJoin, TestGroupingSearch, TestHighlightDedupGrouping, TestJoin, TestRandomDVFaceting, TestRandomFaceting, PathHierarchyTokenizerFactoryTest, ProtectedTermFilterFactoryTest, TokenizerChainTest, TestLuceneIndexBackCompat, TestEmbeddedSolrServerAdminHandler, AssignBackwardCompatibilityTest, BasicDistributedZk2Test, BasicZkTest, ChaosMonkeyNothingIsSafeTest, ChaosMonkeyNothingIsSafeWithPullReplicasTest, ChaosMonkeySafeLeaderWithPullReplicasTest, DeleteLastCustomShardedReplicaTest, DeleteNodeTest, DistributedVersionInfoTest, LeaderTragicEventTest, LeaderVoteWaitTimeoutTest, PackageManagerCLITest, ReplaceNodeNoTargetTest, ReplaceNodeTest, ReplicationFactorTest, TestCloudSearcherWarming, TestSSLRandomization, TestStressInPlaceUpdates, TestUtilizeNode, ZkControllerTest, CollectionReloadTest, CollectionsAPIAsyncDistributedZkTest, AutoAddReplicasIntegrationTest, NodeLostTriggerIntegrationTest]
[junit4] Completed [578/913 (3!)] on J2 in 30.81s, 2 tests, 1 failure <<< FAILURES!
[...truncated 53454 lines...]
[repro] Jenkins log URL: https://jenkins.thetaphi.de/job/Lucene-Solr-master-MacOSX/6065/consoleText
[repro] Revision: 675956c0041b18d48a7c059ea458c49f5310d74a
[repro] Ant options: "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC"
[repro] Repro line: ant test -Dtestcase=TestSimScenario -Dtests.method=testSuggestions -Dtests.seed=3E1E65615723D156 -Dtests.slow=true -Dtests.locale=ar-DJ -Dtests.timezone=Africa/Asmera -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] Repro line: ant test -Dtestcase=TestNamedUpdateProcessors -Dtests.method=test -Dtests.seed=3E1E65615723D156 -Dtests.slow=true -Dtests.locale=de-LU -Dtests.timezone=Antarctica/Syowa -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] Repro line: ant test -Dtestcase=NodeLostTriggerIntegrationTest -Dtests.method=testNodeLostTrigger -Dtests.seed=3E1E65615723D156 -Dtests.slow=true -Dtests.locale=lv -Dtests.timezone=Australia/Hobart -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[repro] JUnit rest result XML files will be moved to: ./repro-reports
[repro] ant clean
[...truncated 6 lines...]
[repro] Test suites by module:
[repro] solr/core
[repro] TestNamedUpdateProcessors
[repro] NodeLostTriggerIntegrationTest
[repro] TestSimScenario
[repro] ant compile-test
[...truncated 3158 lines...]
[repro] ant test-nocompile -Dtests.dups=5 -Dtests.maxfailures=15 -Dtests.class="*.TestNamedUpdateProcessors|*.NodeLostTriggerIntegrationTest|*.TestSimScenario" -Dtests.showOutput=onerror "-Dargs=-XX:-UseCompressedOops -XX:+UseParallelGC" -Dtests.seed=3E1E65615723D156 -Dtests.slow=true -Dtests.locale=de-LU -Dtests.timezone=Antarctica/Syowa -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[...truncated 141 lines...]
[repro] Failures w/original seeds:
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.NodeLostTriggerIntegrationTest
[repro] 0/5 failed: org.apache.solr.cloud.autoscaling.sim.TestSimScenario
[repro] 0/5 failed: org.apache.solr.update.processor.TestNamedUpdateProcessors
[repro] Exiting with code 0
[...truncated 73 lines...]