Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-master/1758/
5 tests failed. FAILED: junit.framework.TestSuite.org.apache.solr.cloud.autoscaling.AutoScalingHandlerTest Error Message: ObjectTracker found 2 object(s) that were not released!!! [SolrZkClient, ZkStateReader] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.SolrZkClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:203) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:126) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:116) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:306) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.ZkStateReader at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:328) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) expected null, but was:<ObjectTracker found 2 object(s) that were not released!!! [SolrZkClient, ZkStateReader] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.SolrZkClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:203) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:126) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:116) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:306) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.ZkStateReader at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:328) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) > Stack Trace: java.lang.AssertionError: ObjectTracker found 2 object(s) that were not released!!! [SolrZkClient, ZkStateReader] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.SolrZkClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:203) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:126) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:116) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:306) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.ZkStateReader at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:328) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) expected null, but was:<ObjectTracker found 2 object(s) that were not released!!! [SolrZkClient, ZkStateReader] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.SolrZkClient at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:203) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:126) at org.apache.solr.common.cloud.SolrZkClient.<init>(SolrZkClient.java:116) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:306) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException: org.apache.solr.common.cloud.ZkStateReader at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.common.cloud.ZkStateReader.<init>(ZkStateReader.java:328) at org.apache.solr.client.solrj.impl.ZkClientClusterStateProvider.connect(ZkClientClusterStateProvider.java:160) at org.apache.solr.client.solrj.impl.CloudSolrClient.connect(CloudSolrClient.java:399) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:827) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:817) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:207) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:224) at org.apache.solr.client.solrj.impl.SolrClientCloudManager.request(SolrClientCloudManager.java:115) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.waitForTaskToFinish(ExecutePlanAction.java:132) at org.apache.solr.cloud.autoscaling.ExecutePlanAction.process(ExecutePlanAction.java:85) at org.apache.solr.cloud.autoscaling.ScheduledTriggers.lambda$null$3(ScheduledTriggers.java:324) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) > at __randomizedtesting.SeedInfo.seed([E22E2F75F8452317]: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.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:322) at sun.reflect.GeneratedMethodAccessor95.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1750) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:901) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.autoscaling.AutoScalingHandlerTest Error Message: 3 threads leaked from SUITE scope at org.apache.solr.cloud.autoscaling.AutoScalingHandlerTest: 1) Thread[id=30980, name=AutoscalingActionExecutor-5967-thread-1-EventThread, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:504) 2) Thread[id=30981, name=zkConnectionManagerCallback-5761-thread-1, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 3) Thread[id=30979, name=AutoscalingActionExecutor-5967-thread-1-SendThread(lucene2-us-west.apache.org:38307), state=TIMED_WAITING, group=TGRP-AutoScalingHandlerTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1049) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 3 threads leaked from SUITE scope at org.apache.solr.cloud.autoscaling.AutoScalingHandlerTest: 1) Thread[id=30980, name=AutoscalingActionExecutor-5967-thread-1-EventThread, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:504) 2) Thread[id=30981, name=zkConnectionManagerCallback-5761-thread-1, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 3) Thread[id=30979, name=AutoscalingActionExecutor-5967-thread-1-SendThread(lucene2-us-west.apache.org:38307), state=TIMED_WAITING, group=TGRP-AutoScalingHandlerTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1049) at __randomizedtesting.SeedInfo.seed([E22E2F75F8452317]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.autoscaling.AutoScalingHandlerTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id=30981, name=zkConnectionManagerCallback-5761-thread-1, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=30979, name=AutoscalingActionExecutor-5967-thread-1-SendThread(lucene2-us-west.apache.org:38307), state=TIMED_WAITING, group=TGRP-AutoScalingHandlerTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:152) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1062) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated: 1) Thread[id=30981, name=zkConnectionManagerCallback-5761-thread-1, state=WAITING, group=TGRP-AutoScalingHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=30979, name=AutoscalingActionExecutor-5967-thread-1-SendThread(lucene2-us-west.apache.org:38307), state=TIMED_WAITING, group=TGRP-AutoScalingHandlerTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:152) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1062) at __randomizedtesting.SeedInfo.seed([E22E2F75F8452317]:0) FAILED: junit.framework.TestSuite.org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest Error Message: 1 thread leaked from SUITE scope at org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest: 1) Thread[id=23946, name=zkConnectionManagerCallback-9038-thread-1, state=WAITING, group=TGRP-AutoscalingHistoryHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest: 1) Thread[id=23946, name=zkConnectionManagerCallback-9038-thread-1, state=WAITING, group=TGRP-AutoscalingHistoryHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([E22E2F75F8452317]:0) FAILED: junit.framework.TestSuite.org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id=23946, name=zkConnectionManagerCallback-9038-thread-1, state=WAITING, group=TGRP-AutoscalingHistoryHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated: 1) Thread[id=23946, name=zkConnectionManagerCallback-9038-thread-1, state=WAITING, group=TGRP-AutoscalingHistoryHandlerTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([E22E2F75F8452317]:0) Build Log: [...truncated 14544 lines...] [junit4] Suite: org.apache.solr.handler.admin.AutoscalingHistoryHandlerTest [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/init-core-data-001 [junit4] 2> 3470063 WARN (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=2 numCloses=2 [junit4] 2> 3470063 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 3470064 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) [junit4] 2> 3470064 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 3470065 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/tempDir-001 [junit4] 2> 3470065 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 3470079 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 3470080 INFO (ZkTestServer Run Thread) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 3470181 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:35913 [junit4] 2> 3470181 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.ZkTestServer parse host and port list: 127.0.0.1:35913 [junit4] 2> 3470181 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1 35913 [junit4] 2> 3470254 INFO (zkConnectionManagerCallback-8908-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470270 INFO (zkConnectionManagerCallback-8910-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470310 INFO (zkConnectionManagerCallback-8912-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470318 WARN (jetty-launcher-8913-thread-1) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time [junit4] 2> 3470321 WARN (jetty-launcher-8913-thread-2) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0) [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ... [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12 [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Start Jetty (original configured port=0) [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Trying to start Jetty on port 0 try number 1 ... [junit4] 2> 3470321 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 1.8.0_191-b12 [junit4] 2> 3470330 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 3470330 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 3470330 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.session node0 Scavenging every 600000ms [junit4] 2> 3470331 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@74e384c1{/solr,null,AVAILABLE} [junit4] 2> 3470332 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 [junit4] 2> 3470332 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.session No SessionScavenger set, using defaults [junit4] 2> 3470332 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.session node0 Scavenging every 600000ms [junit4] 2> 3470333 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@41bc17f1{/solr,null,AVAILABLE} [junit4] 2> 3470333 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@396c05b8{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:43888} [junit4] 2> 3470333 INFO (jetty-launcher-8913-thread-2) [ ] o.e.j.s.Server Started @3470689ms [junit4] 2> 3470333 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=43888} [junit4] 2> 3470334 ERROR (jetty-launcher-8913-thread-2) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 3470334 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 3470334 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0 [junit4] 2> 3470334 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 3470334 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 3470334 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-01-24T22:15:26.791Z [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@171ac681{HTTP/1.1,[http/1.1, h2c]}{127.0.0.1:36858} [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.e.j.s.Server Started @3470701ms [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=36858} [junit4] 2> 3470346 ERROR (jetty-launcher-8913-thread-1) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 9.0.0 [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 3470346 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2019-01-24T22:15:26.803Z [junit4] 2> 3470350 INFO (zkConnectionManagerCallback-8915-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470350 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 3470374 INFO (zkConnectionManagerCallback-8917-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470378 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 3470871 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true] [junit4] 2> 3470873 WARN (jetty-launcher-8913-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@71fe80c5[provider=null,keyStore=null,trustStore=null] [junit4] 2> 3470887 WARN (jetty-launcher-8913-thread-1) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@7fb73349[provider=null,keyStore=null,trustStore=null] [junit4] 2> 3470888 INFO (jetty-launcher-8913-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35913/solr [junit4] 2> 3470892 INFO (zkConnectionManagerCallback-8923-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3470950 INFO (zkConnectionManagerCallback-8925-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471051 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:36858_solr [junit4] 2> 3471051 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer Overseer (id=74069911486464006-127.0.0.1:36858_solr-n_0000000000) starting [junit4] 2> 3471093 INFO (zkConnectionManagerCallback-8932-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471096 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35913/solr ready [junit4] 2> 3471106 INFO (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer Starting to work on the main queue : 127.0.0.1:36858_solr [junit4] 2> 3471133 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36858_solr [junit4] 2> 3471148 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Adding .auto_add_replicas and .scheduled_maintenance triggers [junit4] 2> 3471149 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Refreshing /autoscaling.json with znode version 1 [junit4] 2> 3471153 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 0 [junit4] 2> 3471153 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Processed trigger updates upto znodeVersion 1 [junit4] 2> 3471162 INFO (zkCallback-8931-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 3471176 INFO (zkCallback-8924-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 3471190 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.NodeLostTrigger NodeLostTrigger .auto_add_replicas - Initial livenodes: [127.0.0.1:36858_solr] [junit4] 2> 3471204 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread -- cleaning old nodeLost / nodeAdded markers [junit4] 2> 3471204 DEBUG (OverseerAutoScalingTriggerThread-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [ ] o.a.s.c.a.OverseerTriggerThread Current znodeVersion 1, lastZnodeVersion 1 [junit4] 2> 3471205 DEBUG (ScheduledTrigger-4496-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> 3471231 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 3471330 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true] [junit4] 2> 3471359 WARN (jetty-launcher-8913-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@42c2ee8[provider=null,keyStore=null,trustStore=null] [junit4] 2> 3471376 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36858.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471392 WARN (jetty-launcher-8913-thread-2) [ ] o.e.j.u.s.S.config No Client EndPointIdentificationAlgorithm configured for SslContextFactory@3e5b80fc[provider=null,keyStore=null,trustStore=null] [junit4] 2> 3471393 INFO (jetty-launcher-8913-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:35913/solr [junit4] 2> 3471416 INFO (zkConnectionManagerCallback-8939-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471434 INFO (zkConnectionManagerCallback-8941-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471438 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 3471441 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.ZkController Publish node=127.0.0.1:43888_solr as DOWN [junit4] 2> 3471442 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"downnode", [junit4] 2> "node_name":"127.0.0.1:43888_solr"} current state version: 0 [junit4] 2> 3471442 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.NodeMutator DownNode state invoked for node: 127.0.0.1:43888_solr [junit4] 2> 3471442 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 3471442 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43888_solr [junit4] 2> 3471443 INFO (zkCallback-8931-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 3471443 INFO (zkCallback-8924-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 3471452 INFO (zkCallback-8940-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 3471539 INFO (zkConnectionManagerCallback-8948-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471540 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 3471541 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35913/solr ready [junit4] 2> 3471547 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36858.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471547 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36858.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471548 INFO (jetty-launcher-8913-thread-1) [n:127.0.0.1:36858_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/tempDir-001/node1/. [junit4] 2> 3471559 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. [junit4] 2> 3471604 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43888.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471659 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43888.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471659 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_43888.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3471660 INFO (jetty-launcher-8913-thread-2) [n:127.0.0.1:43888_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/tempDir-001/node2/. [junit4] 2> 3471884 INFO (zkConnectionManagerCallback-8954-thread-1) [ ] o.a.s.c.c.ConnectionManager zkClient has connected [junit4] 2> 3471887 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 3471887 INFO (SUITE-AutoscalingHistoryHandlerTest-seed#[E22E2F75F8452317]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:35913/solr ready [junit4] 2> 3471895 INFO (qtp1826677897-23684) [n:127.0.0.1:36858_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:36858_solr&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 3471973 INFO (OverseerThreadFactory-4498-thread-1-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection .system [junit4] 2> 3471980 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "name":".system", [junit4] 2> "fromApi":"true", [junit4] 2> "numShards":1, [junit4] 2> "createNodeSet":"127.0.0.1:36858_solr", [junit4] 2> "nrtReplicas":"1", [junit4] 2> "stateFormat":"2", [junit4] 2> "replicationFactor":"1", [junit4] 2> "operation":"create"} current state version: 0 [junit4] 2> 3471980 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: .system [junit4] 2> 3471981 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/.system/state.json [junit4] 2> 3472083 DEBUG (OverseerThreadFactory-4498-thread-1-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 3472085 INFO (qtp1826677897-23678) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472086 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472086 INFO (qtp1826677897-23682) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472087 INFO (qtp1826677897-23681) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472088 INFO (qtp1826677897-23678) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472094 INFO (qtp1193969688-23693) [n:127.0.0.1:43888_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472095 INFO (qtp1193969688-23691) [n:127.0.0.1:43888_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472096 INFO (qtp1193969688-23688) [n:127.0.0.1:43888_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472097 INFO (qtp1193969688-23687) [n:127.0.0.1:43888_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472098 INFO (qtp1193969688-23692) [n:127.0.0.1:43888_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3472099 DEBUG (OverseerThreadFactory-4498-thread-1-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.s.c.a.PolicyHelper New session created [junit4] 2> 3472100 DEBUG (OverseerThreadFactory-4498-thread-1-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.s.c.a.PolicyHelper returnSession, curr-time 30705529494 sessionWrapper.createTime 30705529493090214, this.sessionWrapper.createTime 30705529493090214 [junit4] 2> 3472119 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":".system", [junit4] 2> "shard":"shard1", [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} current state version: 0 [junit4] 2> 3472119 INFO (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":".system", [junit4] 2> "shard":"shard1", [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "type":"NRT", [junit4] 2> "waitForFinalState":"false"} [junit4] 2> 3472120 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.SliceMutator Old Slice: shard1:{ [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active", [junit4] 2> "replicas":{}} [junit4] 2> 3472120 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.SliceMutator New Slice: shard1:{ [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active", [junit4] 2> "replicas":{"core_node2":{ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "state":"down", [junit4] 2> "node_name":null, [junit4] 2> "type":"NRT"}}} [junit4] 2> 3472209 DEBUG (ScheduledTrigger-4496-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> 3472220 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 0 [junit4] 2> 3472230 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr x:.system_shard1_replica_n1] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT [junit4] 2> 3472230 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr x:.system_shard1_replica_n1] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 3472257 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false", [junit4] 2> "operation":"state"} current state version: 0 [junit4] 2> 3472257 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "numShards":"1", [junit4] 2> "state":"down", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false", [junit4] 2> "operation":"state"} [junit4] 2> 3472257 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:36858/solr","node_name":"127.0.0.1:36858_solr","state":"down","type":"NRT","force_set_state":"false"} [junit4] 2> 3472257 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/1)={ [junit4] 2> "pullReplicas":"0", [junit4] 2> "replicationFactor":"1", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"1", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "shards":{"shard1":{ [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active", [junit4] 2> "replicas":{"core_node2":{ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "state":"down", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false"}}}}} [junit4] 2> 3472358 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 1 [junit4] 2> 3473221 DEBUG (ScheduledTrigger-4496-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> 3473274 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 9.0.0 [junit4] 2> 3473291 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but managed schema resource managed-schema not found - loading non-managed schema schema.xml instead [junit4] 2> 3473293 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema [.system_shard1_replica_n1] Schema name=_system collection or core [junit4] 2> 3473297 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.IndexSchema Loaded schema _system collection or core/1.1 with uniqueid field id [junit4] 2> 3473315 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchema Created and persisted managed schema znode at /configs/.system/managed-schema [junit4] 2> 3473326 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema in ZooKeeper, renamed the non-managed schema /configs/.system/schema.xml to /configs/.system/schema.xml.bak [junit4] 2> 3473326 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.CoreContainer Creating SolrCore '.system_shard1_replica_n1' using configuration from collection .system, trusted=true [junit4] 2> 3473334 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_36858.solr.core..system.shard1.replica_n1' (registry 'solr.core..system.shard1.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@4a26e727 [junit4] 2> 3473336 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [[.system_shard1_replica_n1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/tempDir-001/node1/.system_shard1_replica_n1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/build/solr-core/test/J1/temp/solr.handler.admin.AutoscalingHistoryHandlerTest_E22E2F75F8452317-001/tempDir-001/node1/./.system_shard1_replica_n1/data/] [junit4] 2> 3473623 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 3473623 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 3473625 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: if 1 uncommitted docs; [junit4] 2> 3473625 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 3473626 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4428a5a6[.system_shard1_replica_n1] main] [junit4] 2> 3473628 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/.system [junit4] 2> 3473629 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/.system [junit4] 2> 3473629 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Creating ZooKeeper watch for the managed schema at /configs/.system/managed-schema [junit4] 2> 3473630 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.ZkIndexSchemaReader Current schema version 0 is already the latest [junit4] 2> 3473630 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 3473630 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1623581660374106112 [junit4] 2> 3473633 INFO (searcherExecutor-4510-thread-1-processing-n:127.0.0.1:36858_solr x:.system_shard1_replica_n1 c:.system s:shard1 r:core_node2) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SolrCore [.system_shard1_replica_n1] Registered new searcher Searcher@4428a5a6[.system_shard1_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 3473636 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ZkShardTerms Successful update of terms at /collections/.system/terms/shard1 to Terms{values={core_node2=0}, version=0} [junit4] 2> 3473637 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase make sure parent is created /collections/.system/leaders/shard1 [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:36858/solr/.system_shard1_replica_n1/ [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:36858/solr/.system_shard1_replica_n1/ has no replicas [junit4] 2> 3473639 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContextBase Creating leader registration node /collections/.system/leaders/shard1/leader after winning as /collections/.system/leader_elect/shard1/election/74069911486464006-core_node2-n_0000000000 [junit4] 2> 3473641 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:36858/solr/.system_shard1_replica_n1/ shard1 [junit4] 2> 3473641 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "operation":"leader", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "state":"active"} current state version: 0 [junit4] 2> 3473742 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 2 [junit4] 2> 3473742 INFO (zkCallback-8924-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2]) [junit4] 2> 3473744 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 3473746 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr c:.system s:shard1 r:core_node2 x:.system_shard1_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=.system&newCollection=true&name=.system_shard1_replica_n1&action=CREATE&numShards=1&collection=.system&shard=shard1&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1516 [junit4] 2> 3473756 DEBUG (OverseerThreadFactory-4498-thread-1-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.s.c.a.PolicyHelper session set to NULL [junit4] 2> 3473757 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false", [junit4] 2> "operation":"state"} current state version: 0 [junit4] 2> 3473757 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "core_node_name":"core_node2", [junit4] 2> "roles":null, [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "numShards":"1", [junit4] 2> "state":"active", [junit4] 2> "shard":"shard1", [junit4] 2> "collection":".system", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false", [junit4] 2> "operation":"state"} [junit4] 2> 3473757 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Will update state for replica: core_node2:{"core":".system_shard1_replica_n1","base_url":"http://127.0.0.1:36858/solr","node_name":"127.0.0.1:36858_solr","state":"active","type":"NRT","force_set_state":"false","leader":"true"} [junit4] 2> 3473757 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ReplicaMutator Collection is now: DocCollection(.system//collections/.system/state.json/3)={ [junit4] 2> "pullReplicas":"0", [junit4] 2> "replicationFactor":"1", [junit4] 2> "router":{"name":"compositeId"}, [junit4] 2> "maxShardsPerNode":"1", [junit4] 2> "autoAddReplicas":"false", [junit4] 2> "nrtReplicas":"1", [junit4] 2> "tlogReplicas":"0", [junit4] 2> "shards":{"shard1":{ [junit4] 2> "range":"80000000-7fffffff", [junit4] 2> "state":"active", [junit4] 2> "replicas":{"core_node2":{ [junit4] 2> "core":".system_shard1_replica_n1", [junit4] 2> "base_url":"http://127.0.0.1:36858/solr", [junit4] 2> "node_name":"127.0.0.1:36858_solr", [junit4] 2> "state":"active", [junit4] 2> "type":"NRT", [junit4] 2> "force_set_state":"false", [junit4] 2> "leader":"true"}}}}} [junit4] 2> 3473758 INFO (zkCallback-8924-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2]) [junit4] 2> 3473787 INFO (qtp1826677897-23684) [n:127.0.0.1:36858_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 45 seconds. Check all shard replicas [junit4] 2> 3473858 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to update_collection /collections/.system/state.json version: 3 [junit4] 2> 3473858 INFO (zkCallback-8924-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2]) [junit4] 2> 3473859 INFO (zkCallback-8924-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2]) [junit4] 2> 3473859 INFO (qtp1826677897-23684) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={name=.system&nrtReplicas=1&action=CREATE&numShards=1&createNodeSet=127.0.0.1:36858_solr&wt=javabin&version=2} status=0 QTime=1963 [junit4] 2> 3473886 INFO (zkCallback-8924-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/.system/state.json] for collection [.system] has occurred - updating... (live nodes size: [2]) [junit4] 2> 3473891 INFO (qtp1826677897-23682) [n:127.0.0.1:36858_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params maxShardsPerNode=3&name=AutoscalingHistoryHandlerTest_collection&nrtReplicas=3&action=CREATE&numShards=1&createNodeSet=127.0.0.1:43888_solr&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 3473911 INFO (OverseerCollectionConfigSetProcessor-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper [junit4] 2> 3473911 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.a.c.CreateCollectionCmd Create collection AutoscalingHistoryHandlerTest_collection [junit4] 2> 3473913 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/protwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/protwords.txt [junit4] 2> 3473917 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/managed-schema to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/managed-schema [junit4] 2> 3473922 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/solrconfig.xml to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/solrconfig.xml [junit4] 2> 3473925 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/synonyms.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/synonyms.txt [junit4] 2> 3473928 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/stopwords.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/stopwords.txt [junit4] 2> 3473933 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/params.json to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/params.json [junit4] 2> 3473936 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_it.txt [junit4] 2> 3473938 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_no.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_no.txt [junit4] 2> 3473940 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hy.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hy.txt [junit4] 2> 3473944 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stemdict_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stemdict_nl.txt [junit4] 2> 3473950 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ca.txt [junit4] 2> 3473952 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_id.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_id.txt [junit4] 2> 3473954 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ga.txt [junit4] 2> 3474001 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_da.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_da.txt [junit4] 2> 3474002 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hi.txt [junit4] 2> 3474003 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ja.txt [junit4] 2> 3474004 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_pt.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_pt.txt [junit4] 2> 3474005 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_hu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_hu.txt [junit4] 2> 3474007 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_el.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_el.txt [junit4] 2> 3474008 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ru.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ru.txt [junit4] 2> 3474010 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_tr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_tr.txt [junit4] 2> 3474012 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ar.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ar.txt [junit4] 2> 3474014 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/userdict_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/userdict_ja.txt [junit4] 2> 3474015 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_it.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_it.txt [junit4] 2> 3474017 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_eu.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_eu.txt [junit4] 2> 3474018 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_cz.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_cz.txt [junit4] 2> 3474020 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stoptags_ja.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stoptags_ja.txt [junit4] 2> 3474026 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_fr.txt [junit4] 2> 3474029 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fa.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fa.txt [junit4] 2> 3474033 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_de.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_de.txt [junit4] 2> 3474038 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/contractions_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/contractions_ga.txt [junit4] 2> 3474039 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ca.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ca.txt [junit4] 2> 3474044 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_nl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_nl.txt [junit4] 2> 3474046 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_bg.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_bg.txt [junit4] 2> 3474049 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_es.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_es.txt [junit4] 2> 3474052 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_en.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_en.txt [junit4] 2> 3474054 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_lv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_lv.txt [junit4] 2> 3474065 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_th.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_th.txt [junit4] 2> 3474066 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_ro.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_ro.txt [junit4] 2> 3474079 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fr.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fr.txt [junit4] 2> 3474080 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_sv.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_sv.txt [junit4] 2> 3474081 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_fi.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_fi.txt [junit4] 2> 3474085 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/hyphenations_ga.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/hyphenations_ga.txt [junit4] 2> 3474086 INFO (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.c.ZkConfigManager Copying zk node /configs/_default/lang/stopwords_gl.txt to /configs/AutoscalingHistoryHandlerTest_collection.AUTOCREATED/lang/stopwords_gl.txt [junit4] 2> 3474092 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.Overseer processMessage: queueSize: 1, message = { [junit4] 2> "name":"AutoscalingHistoryHandlerTest_collection", [junit4] 2> "fromApi":"true", [junit4] 2> "numShards":"1", [junit4] 2> "maxShardsPerNode":"3", [junit4] 2> "createNodeSet":"127.0.0.1:43888_solr", [junit4] 2> "nrtReplicas":"3", [junit4] 2> "stateFormat":"2", [junit4] 2> "replicationFactor":"3", [junit4] 2> "operation":"create"} current state version: 0 [junit4] 2> 3474092 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ClusterStateMutator building a new cName: AutoscalingHistoryHandlerTest_collection [junit4] 2> 3474192 DEBUG (OverseerStateUpdate-74069911486464006-127.0.0.1:36858_solr-n_0000000000) [n:127.0.0.1:36858_solr ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/AutoscalingHistoryHandlerTest_collection/state.json [junit4] 2> 3474221 DEBUG (ScheduledTrigger-4496-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> 3474293 WARN (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.a.c.CreateCollectionCmd Specified number of replicas of 3 on collection AutoscalingHistoryHandlerTest_collection is higher than the number of Solr instances currently live or live and part of your createNodeSet(1). It's unusual to run two replica of the same slice on the same Solr-instance. [junit4] 2> 3474293 DEBUG (OverseerThreadFactory-4498-thread-2-processing-n:127.0.0.1:36858_solr) [n:127.0.0.1:36858_solr ] o.a.s.c.s.c.a.PolicyHelper Creating a new session [junit4] 2> 3474296 INFO (qtp1826677897-23681) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core..system.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=2 [junit4] 2> 3474297 INFO (qtp1826677897-23678) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core..system.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0 [junit4] 2> 3474297 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={wt=javabin&version=2&key=solr.core..system.shard1.replica_n1:INDEX.sizeInBytes} status=0 QTime=0 [junit4] 2> 3474299 INFO (qtp1826677897-23684) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3474299 INFO (qtp1826677897-23681) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3474300 INFO (qtp1826677897-23678) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3474301 INFO (qtp1826677897-23680) [n:127.0.0.1:36858_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/metrics params={prefix=CONTAINER.fs.usableSpace,CONTAINER.fs.totalSpace,CORE.coreName&wt=javabin&version=2&group=solr.node,solr.core} status=0 QTime=0 [junit4] 2> 3474302 INFO (qtp1826677897-23684) [n:127.0.0.1:36858_solr ] [...truncated too long message...] as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: ivy-availability-check: [loadresource] Do not set property disallowed.ivy.jars.list as its length is 0. -ivy-fail-disallowed-ivy-version: ivy-fail: ivy-fail: ivy-configure: [ivy:configure] :: loading settings :: file = /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/lucene/top-level-ivy-settings.xml resolve: jar-checksums: [mkdir] Created dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1791167745 [copy] Copying 257 files to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1791167745 [delete] Deleting directory /home/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-master/checkout/solr/null1791167745 check-working-copy: [ivy:cachepath] :: resolving dependencies :: org.eclipse.jgit#org.eclipse.jgit-caller;working [ivy:cachepath] confs: [default] [ivy:cachepath] found org.eclipse.jgit#org.eclipse.jgit;4.6.0.201612231935-r in public [ivy:cachepath] found com.jcraft#jsch;0.1.53 in public [ivy:cachepath] found com.googlecode.javaewah#JavaEWAH;1.1.6 in public [ivy:cachepath] found org.apache.httpcomponents#httpclient;4.3.6 in public [ivy:cachepath] found org.apache.httpcomponents#httpcore;4.3.3 in public [ivy:cachepath] found commons-logging#commons-logging;1.1.3 in public [ivy:cachepath] found commons-codec#commons-codec;1.6 in public [ivy:cachepath] found org.slf4j#slf4j-api;1.7.2 in public [ivy:cachepath] :: resolution report :: resolve 93ms :: artifacts dl 15ms --------------------------------------------------------------------- | | modules || artifacts | | conf | number| search|dwnlded|evicted|| number|dwnlded| --------------------------------------------------------------------- | default | 8 | 0 | 0 | 0 || 8 | 0 | --------------------------------------------------------------------- [wc-checker] Initializing working copy... [wc-checker] SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder". [wc-checker] SLF4J: Defaulting to no-operation (NOP) logger implementation [wc-checker] SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details. [wc-checker] Checking working copy status... -jenkins-base: BUILD SUCCESSFUL Total time: 575 minutes 27 seconds Archiving artifacts java.lang.InterruptedException: no matches found within 10000 at hudson.FilePath$ValidateAntFileMask.hasMatch(FilePath.java:2847) at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2726) at hudson.FilePath$ValidateAntFileMask.invoke(FilePath.java:2707) at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3086) Also: hudson.remoting.Channel$CallSiteStackTrace: Remote call to lucene2 at hudson.remoting.Channel.attachCallSiteStackTrace(Channel.java:1741) at hudson.remoting.UserRequest$ExceptionResponse.retrieve(UserRequest.java:357) at hudson.remoting.Channel.call(Channel.java:955) at hudson.FilePath.act(FilePath.java:1072) at hudson.FilePath.act(FilePath.java:1061) at hudson.FilePath.validateAntFileMask(FilePath.java:2705) at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243) at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81) at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20) at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744) at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690) at hudson.model.Build$BuildExecution.post2(Build.java:186) at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635) at hudson.model.Run.execute(Run.java:1835) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429) Caused: hudson.FilePath$TunneledInterruptedException at hudson.FilePath$FileCallableWrapper.call(FilePath.java:3088) at hudson.remoting.UserRequest.perform(UserRequest.java:212) at hudson.remoting.UserRequest.perform(UserRequest.java:54) at hudson.remoting.Request$2.run(Request.java:369) at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Caused: java.lang.InterruptedException: java.lang.InterruptedException: no matches found within 10000 at hudson.FilePath.act(FilePath.java:1074) at hudson.FilePath.act(FilePath.java:1061) at hudson.FilePath.validateAntFileMask(FilePath.java:2705) at hudson.tasks.ArtifactArchiver.perform(ArtifactArchiver.java:243) at hudson.tasks.BuildStepCompatibilityLayer.perform(BuildStepCompatibilityLayer.java:81) at hudson.tasks.BuildStepMonitor$1.perform(BuildStepMonitor.java:20) at hudson.model.AbstractBuild$AbstractBuildExecution.perform(AbstractBuild.java:744) at hudson.model.AbstractBuild$AbstractBuildExecution.performAllBuildSteps(AbstractBuild.java:690) at hudson.model.Build$BuildExecution.post2(Build.java:186) at hudson.model.AbstractBuild$AbstractBuildExecution.post(AbstractBuild.java:635) at hudson.model.Run.execute(Run.java:1835) at hudson.model.FreeStyleBuild.run(FreeStyleBuild.java:43) at hudson.model.ResourceController.execute(ResourceController.java:97) at hudson.model.Executor.run(Executor.java:429) No artifacts found that match the file pattern "**/*.events,heapdumps/**,**/hs_err_pid*". Configuration error? Recording test results Build step 'Publish JUnit test result report' changed build result to UNSTABLE Email was triggered for: Unstable (Test Failures) Sending email for trigger: Unstable (Test Failures)
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org