Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.x-MacOSX/32/ Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC
5 tests failed. FAILED: org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI Error Message: Error from server at http://127.0.0.1:50823/solr: ADDREPLICA failed to create replica Stack Trace: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:50823/solr: ADDREPLICA failed to create replica at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46:B43FFA704D30093E]:0) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:626) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:252) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:241) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:483) at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:413) at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1121) at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:862) at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:793) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:178) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:195) at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:103) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.DeleteInactiveReplicaTest.deleteInactiveReplicaTest Error Message: Expected a cluster of 2 shards and 2 replicas null Live Nodes: [127.0.0.1:50937_solr, 127.0.0.1:50938_solr, 127.0.0.1:50936_solr, 127.0.0.1:50939_solr] Last available state: null Stack Trace: java.lang.AssertionError: Expected a cluster of 2 shards and 2 replicas null Live Nodes: [127.0.0.1:50937_solr, 127.0.0.1:50938_solr, 127.0.0.1:50936_solr, 127.0.0.1:50939_solr] Last available state: null at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46:13E0EFE83F0BC9A4]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269) at org.apache.solr.cloud.DeleteInactiveReplicaTest.deleteInactiveReplicaTest(DeleteInactiveReplicaTest.java:58) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at java.lang.Thread.run(Thread.java:748) FAILED: org.apache.solr.cloud.MissingSegmentRecoveryTest.testLeaderRecovery Error Message: Expected a collection with one shard and two replicas null Live Nodes: [127.0.0.1:51460_solr, 127.0.0.1:51461_solr] Last available state: DocCollection(MissingSegmentRecoveryTest//collections/MissingSegmentRecoveryTest/state.json/7)={ "pullReplicas":"0", "replicationFactor":"2", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{ "core_node1":{ "core":"MissingSegmentRecoveryTest_shard1_replica_n1", "base_url":"http://127.0.0.1:51461/solr";, "node_name":"127.0.0.1:51461_solr", "state":"down", "type":"NRT"}, "core_node2":{ "core":"MissingSegmentRecoveryTest_shard1_replica_n2", "base_url":"http://127.0.0.1:51460/solr";, "node_name":"127.0.0.1:51460_solr", "state":"active", "type":"NRT", "leader":"true"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"1", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0"} Stack Trace: java.lang.AssertionError: Expected a collection with one shard and two replicas null Live Nodes: [127.0.0.1:51460_solr, 127.0.0.1:51461_solr] Last available state: DocCollection(MissingSegmentRecoveryTest//collections/MissingSegmentRecoveryTest/state.json/7)={ "pullReplicas":"0", "replicationFactor":"2", "shards":{"shard1":{ "range":"80000000-7fffffff", "state":"active", "replicas":{ "core_node1":{ "core":"MissingSegmentRecoveryTest_shard1_replica_n1", "base_url":"http://127.0.0.1:51461/solr";, "node_name":"127.0.0.1:51461_solr", "state":"down", "type":"NRT"}, "core_node2":{ "core":"MissingSegmentRecoveryTest_shard1_replica_n2", "base_url":"http://127.0.0.1:51460/solr";, "node_name":"127.0.0.1:51460_solr", "state":"active", "type":"NRT", "leader":"true"}}}}, "router":{"name":"compositeId"}, "maxShardsPerNode":"1", "autoAddReplicas":"false", "nrtReplicas":"2", "tlogReplicas":"0"} at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46:8E8BEC18298B095B]:0) at org.junit.Assert.fail(Assert.java:93) at org.apache.solr.cloud.SolrCloudTestCase.waitForState(SolrCloudTestCase.java:269) at org.apache.solr.cloud.MissingSegmentRecoveryTest.testLeaderRecovery(MissingSegmentRecoveryTest.java:105) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957) at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57) at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49) at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45) at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48) at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64) at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47) at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36) at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368) at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817) at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468) at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863) 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.MissingSegmentRecoveryTest Error Message: 9 threads leaked from SUITE scope at org.apache.solr.cloud.MissingSegmentRecoveryTest: 1) Thread[id=19288, name=zkCallback-2726-thread-6, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=19285, name=zkCallback-2726-thread-3-processing-n:127.0.0.1:51461_solr, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:111) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:70) at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:303) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:512) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:467) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454) at org.apache.solr.cloud.OverseerElectionContext.runLeaderProcess(ElectionContext.java:763) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:170) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:135) at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56) at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:348) at org.apache.solr.common.cloud.SolrZkClient$3.lambda$process$0(SolrZkClient.java:269) at org.apache.solr.common.cloud.SolrZkClient$3$$Lambda$175/809255178.run(Unknown Source) 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:188) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$105/403772457.run(Unknown Source) 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) 3) Thread[id=19287, name=zkCallback-2726-thread-5, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=19264, name=Connection evictor, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) 6) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=19269, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-EventThread, state=WAITING, group=TGRP-MissingSegmentRecoveryTest] 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:501) 8) Thread[id=19263, name=Connection evictor, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:748) 9) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 9 threads leaked from SUITE scope at org.apache.solr.cloud.MissingSegmentRecoveryTest: 1) Thread[id=19288, name=zkCallback-2726-thread-6, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=19285, name=zkCallback-2726-thread-3-processing-n:127.0.0.1:51461_solr, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.solr.common.cloud.ZkCmdExecutor.retryDelay(ZkCmdExecutor.java:111) at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:70) at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:303) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:512) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:467) at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:454) at org.apache.solr.cloud.OverseerElectionContext.runLeaderProcess(ElectionContext.java:763) at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:170) at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:135) at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:56) at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:348) at org.apache.solr.common.cloud.SolrZkClient$3.lambda$process$0(SolrZkClient.java:269) at org.apache.solr.common.cloud.SolrZkClient$3$$Lambda$175/809255178.run(Unknown Source) 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:188) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor$$Lambda$105/403772457.run(Unknown Source) 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) 3) Thread[id=19287, name=zkCallback-2726-thread-5, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=19264, name=Connection evictor, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) 6) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=19269, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-EventThread, state=WAITING, group=TGRP-MissingSegmentRecoveryTest] 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:501) 8) Thread[id=19263, name=Connection evictor, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) at java.lang.Thread.run(Thread.java:748) 9) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46]:0) FAILED: junit.framework.TestSuite.org.apache.solr.cloud.MissingSegmentRecoveryTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id=19288, name=zkCallback-2726-thread-6, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=19285, name=zkCallback-2726-thread-3, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 3) Thread[id=19287, name=zkCallback-2726-thread-5, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) 5) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 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=19288, name=zkCallback-2726-thread-6, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=19285, name=zkCallback-2726-thread-3, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 3) Thread[id=19287, name=zkCallback-2726-thread-5, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) 5) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46]:0) Build Log: [...truncated 12405 lines...] [junit4] Suite: org.apache.solr.cloud.CustomCollectionTest [junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/init-core-data-001 [junit4] 2> 2201153 WARN (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=1 numCloses=1 [junit4] 2> 2201154 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) w/NUMERIC_DOCVALUES_SYSPROP=false [junit4] 2> 2201157 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN) w/ MAC_OS_X supressed clientAuth [junit4] 2> 2201157 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 4 servers in /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001 [junit4] 2> 2201157 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER [junit4] 2> 2201158 INFO (Thread-3398) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0 [junit4] 2> 2201158 INFO (Thread-3398) [ ] o.a.s.c.ZkTestServer Starting server [junit4] 2> 2201161 ERROR (Thread-3398) [ ] o.a.z.s.ZooKeeperServer ZKShutdownHandler is not registered, so ZooKeeper server won't take any action on ERROR or SHUTDOWN server state changes [junit4] 2> 2201264 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:50820 [junit4] 2> 2201294 INFO (jetty-launcher-2557-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2201294 INFO (jetty-launcher-2557-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2201295 INFO (jetty-launcher-2557-thread-3) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2201297 INFO (jetty-launcher-2557-thread-4) [ ] o.e.j.s.Server jetty-9.3.14.v20161028 [junit4] 2> 2201298 INFO (jetty-launcher-2557-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@5e01c37b{/solr,null,AVAILABLE} [junit4] 2> 2201298 INFO (jetty-launcher-2557-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2d34883{/solr,null,AVAILABLE} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1190de3c{HTTP/1.1,[http/1.1]}{127.0.0.1:50822} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-1) [ ] o.e.j.s.Server Started @2204754ms [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50822} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-4) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4ce84f27{/solr,null,AVAILABLE} [junit4] 2> 2201300 ERROR (jetty-launcher-2557-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-4) [ ] o.e.j.s.AbstractConnector Started ServerConnector@5aeb4502{HTTP/1.1,[http/1.1]}{127.0.0.1:50824} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-4) [ ] o.e.j.s.Server Started @2204754ms [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50824} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3cd83811{HTTP/1.1,[http/1.1]}{127.0.0.1:50823} [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-2) [ ] o.e.j.s.Server Started @2204754ms [junit4] 2> 2201300 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50823} [junit4] 2> 2201300 ERROR (jetty-launcher-2557-thread-4) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2201301 ERROR (jetty-launcher-2557-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.1.0 [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-12T14:01:20.321Z [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.1.0 [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 2201301 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-12T14:01:20.321Z [junit4] 2> 2201302 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.1.0 [junit4] 2> 2201302 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2201302 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 2201302 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-12T14:01:20.322Z [junit4] 2> 2201303 INFO (jetty-launcher-2557-thread-3) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@31d632a0{/solr,null,AVAILABLE} [junit4] 2> 2201304 INFO (jetty-launcher-2557-thread-3) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3db2893e{HTTP/1.1,[http/1.1]}{127.0.0.1:50826} [junit4] 2> 2201304 INFO (jetty-launcher-2557-thread-3) [ ] o.e.j.s.Server Started @2204758ms [junit4] 2> 2201304 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=50826} [junit4] 2> 2201305 ERROR (jetty-launcher-2557-thread-3) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 2201305 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.1.0 [junit4] 2> 2201305 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null [junit4] 2> 2201305 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null, Default config dir: null [junit4] 2> 2201305 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-07-12T14:01:20.325Z [junit4] 2> 2201306 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2201308 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2201309 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2201317 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading... [junit4] 2> 2201331 INFO (jetty-launcher-2557-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50820/solr [junit4] 2> 2201334 INFO (jetty-launcher-2557-thread-4) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50820/solr [junit4] 2> 2201335 INFO (jetty-launcher-2557-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50820/solr [junit4] 2> 2201340 INFO (jetty-launcher-2557-thread-3) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:50820/solr [junit4] 2> 2201541 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2201542 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:50826_solr [junit4] 2> 2201547 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.c.Overseer Overseer (id=98295354502676492-127.0.0.1:50826_solr-n_0000000000) starting [junit4] 2> 2201555 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2201557 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50822_solr [junit4] 2> 2201560 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2201567 INFO (OverseerStateUpdate-98295354502676492-127.0.0.1:50826_solr-n_0000000000) [n:127.0.0.1:50826_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1) [junit4] 2> 2201568 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50826_solr [junit4] 2> 2201573 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2201573 INFO (zkCallback-2579-thread-1-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2) [junit4] 2> 2201618 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2201620 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2) [junit4] 2> 2201621 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2201623 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.c.Overseer Overseer (id=null) closing [junit4] 2> 2201624 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50823_solr [junit4] 2> 2201626 INFO (zkCallback-2578-thread-1-processing-n:127.0.0.1:50823_solr) [n:127.0.0.1:50823_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2201636 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2201637 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2201637 INFO (zkCallback-2579-thread-1-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (3) [junit4] 2> 2201641 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50824_solr [junit4] 2> 2201644 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2201704 INFO (zkCallback-2579-thread-1-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2201705 INFO (zkCallback-2578-thread-1-processing-n:127.0.0.1:50823_solr) [n:127.0.0.1:50823_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2201705 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (3) -> (4) [junit4] 2> 2201791 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50823.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201798 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50823.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201798 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50823.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201799 INFO (jetty-launcher-2557-thread-2) [n:127.0.0.1:50823_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node2/. [junit4] 2> 2201811 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50822.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201814 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50822.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201814 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50822.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201815 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50826.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201817 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50826.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201817 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50826.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201818 INFO (jetty-launcher-2557-thread-3) [n:127.0.0.1:50826_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node3/. [junit4] 2> 2201825 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50824.solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201829 INFO (jetty-launcher-2557-thread-1) [n:127.0.0.1:50822_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node1/. [junit4] 2> 2201831 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50824.solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201831 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50824.solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2201832 INFO (jetty-launcher-2557-thread-4) [n:127.0.0.1:50824_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath /Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node4/. [junit4] 2> 2201935 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2201937 INFO (SUITE-CustomCollectionTest-seed#[DEDE741B70AABF46]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:50820/solr ready [junit4] 2> 2201975 INFO (TEST-CustomCollectionTest.testCreateShardRepFactor-seed#[DEDE741B70AABF46]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testCreateShardRepFactor [junit4] 2> 2201977 INFO (TEST-CustomCollectionTest.testCreateShardRepFactor-seed#[DEDE741B70AABF46]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (4) [junit4] 2> 2201985 INFO (qtp1655650061-18191) [n:127.0.0.1:50823_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params shards=a,b&replicationFactor=1&collection.configName=conf&name=testCreateShardRepFactor&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2201988 INFO (OverseerThreadFactory-8541-thread-1-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.CreateCollectionCmd Create collection testCreateShardRepFactor [junit4] 2> 2202099 INFO (OverseerStateUpdate-98295354502676492-127.0.0.1:50826_solr-n_0000000000) [n:127.0.0.1:50826_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"testCreateShardRepFactor", [junit4] 2> "shard":"a", [junit4] 2> "core":"testCreateShardRepFactor_a_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:50824/solr";, [junit4] 2> "type":"NRT"} [junit4] 2> 2202102 INFO (OverseerStateUpdate-98295354502676492-127.0.0.1:50826_solr-n_0000000000) [n:127.0.0.1:50826_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"ADDREPLICA", [junit4] 2> "collection":"testCreateShardRepFactor", [junit4] 2> "shard":"b", [junit4] 2> "core":"testCreateShardRepFactor_b_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:50822/solr";, [junit4] 2> "type":"NRT"} [junit4] 2> 2202313 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_b_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=b&wt=javabin&version=2&replicaType=NRT [junit4] 2> 2202315 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2202315 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_a_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=a&wt=javabin&version=2&replicaType=NRT [junit4] 2> 2202316 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2202433 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2202434 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2202434 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2202434 INFO (zkCallback-2577-thread-2-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203344 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0 [junit4] 2> 2203345 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0 [junit4] 2> 2203351 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.s.IndexSchema [testCreateShardRepFactor_b_replica_n1] Schema name=cloud-dynamic [junit4] 2> 2203352 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.IndexSchema [testCreateShardRepFactor_a_replica_n1] Schema name=cloud-dynamic [junit4] 2> 2203381 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id [junit4] 2> 2203381 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_b_replica_n1' using configuration from collection testCreateShardRepFactor, trusted=true [junit4] 2> 2203381 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50822.solr.core.testCreateShardRepFactor.b.replica_n1' (registry 'solr.core.testCreateShardRepFactor.b.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2203381 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2203381 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SolrCore [[testCreateShardRepFactor_b_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node1/testCreateShardRepFactor_b_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node1/./testCreateShardRepFactor_b_replica_n1/data/] [junit4] 2> 2203384 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id [junit4] 2> 2203385 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_a_replica_n1' using configuration from collection testCreateShardRepFactor, trusted=true [junit4] 2> 2203385 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50824.solr.core.testCreateShardRepFactor.a.replica_n1' (registry 'solr.core.testCreateShardRepFactor.a.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2203385 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2203385 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore [[testCreateShardRepFactor_a_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node4/testCreateShardRepFactor_a_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node4/./testCreateShardRepFactor_a_replica_n1/data/] [junit4] 2> 2203448 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2203448 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2203450 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2203450 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2203451 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@29abab25[testCreateShardRepFactor_a_replica_n1] main] [junit4] 2> 2203452 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 2203453 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 2203453 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2203453 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2203453 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2203453 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1572725674447208448 [junit4] 2> 2203454 INFO (searcherExecutor-8551-thread-1-processing-n:127.0.0.1:50824_solr x:testCreateShardRepFactor_a_replica_n1 s:a c:testCreateShardRepFactor r:core_node1) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SolrCore [testCreateShardRepFactor_a_replica_n1] Registered new searcher Searcher@29abab25[testCreateShardRepFactor_a_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2203475 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 2203475 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 2203476 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.s.SolrIndexSearcher Opening [Searcher@75905785[testCreateShardRepFactor_b_replica_n1] main] [junit4] 2> 2203478 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf [junit4] 2> 2203478 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf [junit4] 2> 2203479 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000 [junit4] 2> 2203479 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1572725674474471424 [junit4] 2> 2203480 INFO (searcherExecutor-8550-thread-1-processing-n:127.0.0.1:50822_solr x:testCreateShardRepFactor_b_replica_n1 s:b c:testCreateShardRepFactor r:core_node2) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SolrCore [testCreateShardRepFactor_b_replica_n1] Registered new searcher Searcher@75905785[testCreateShardRepFactor_b_replica_n1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:50824/solr/testCreateShardRepFactor_a_replica_n1/ [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:50824/solr/testCreateShardRepFactor_a_replica_n1/ has no replicas [junit4] 2> 2203481 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2203487 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:50824/solr/testCreateShardRepFactor_a_replica_n1/ a [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue. [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:50822/solr/testCreateShardRepFactor_b_replica_n1/ [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.SyncStrategy http://127.0.0.1:50822/solr/testCreateShardRepFactor_b_replica_n1/ has no replicas [junit4] 2> 2203487 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.ShardLeaderElectionContext Found all replicas participating in election, clear LIR [junit4] 2> 2203492 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:50822/solr/testCreateShardRepFactor_b_replica_n1/ b [junit4] 2> 2203596 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203597 INFO (zkCallback-2577-thread-2-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203597 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203596 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203599 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2203600 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.c.ZkController I am the leader, no recovery necessary [junit4] 2> 2203602 INFO (qtp2126415740-18215) [n:127.0.0.1:50824_solr c:testCreateShardRepFactor s:a r:core_node1 x:testCreateShardRepFactor_a_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node1&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_a_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=a&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1287 [junit4] 2> 2203606 INFO (qtp589065031-18204) [n:127.0.0.1:50822_solr c:testCreateShardRepFactor s:b r:core_node2 x:testCreateShardRepFactor_b_replica_n1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&coreNodeName=core_node2&collection.configName=conf&newCollection=true&name=testCreateShardRepFactor_b_replica_n1&action=CREATE&numShards=2&collection=testCreateShardRepFactor&shard=b&wt=javabin&version=2&replicaType=NRT} status=0 QTime=1293 [junit4] 2> 2203611 INFO (qtp1655650061-18191) [n:127.0.0.1:50823_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas [junit4] 2> 2203726 INFO (zkCallback-2577-thread-2-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203726 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203726 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203726 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2203991 INFO (OverseerCollectionConfigSetProcessor-98295354502676492-127.0.0.1:50826_solr-n_0000000000) [n:127.0.0.1:50826_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> 2204617 INFO (qtp1655650061-18191) [n:127.0.0.1:50823_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={shards=a,b&replicationFactor=1&collection.configName=conf&name=testCreateShardRepFactor&router.name=implicit&nrtReplicas=1&action=CREATE&wt=javabin&version=2} status=0 QTime=2632 [junit4] 2> 2204618 INFO (qtp1655650061-18192) [n:127.0.0.1:50823_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :createshard with params action=CREATESHARD&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2 and sendToOCPQueue=true [junit4] 2> 2204622 INFO (OverseerThreadFactory-8541-thread-2-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.CreateShardCmd Create shard invoked: { [junit4] 2> "collection":"testCreateShardRepFactor", [junit4] 2> "shard":"x", [junit4] 2> "operation":"createshard"} [junit4] 2> 2204734 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2204734 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2204734 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2204734 INFO (zkCallback-2577-thread-2-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205638 INFO (OverseerThreadFactory-8541-thread-2-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.CreateShardCmd Creating replica testCreateShardRepFactor_x_replica_n1 as part of slice x of collection testCreateShardRepFactor on 127.0.0.1:50823_solr [junit4] 2> 2205640 INFO (OverseerThreadFactory-8541-thread-2-processing-n:127.0.0.1:50826_solr) [n:127.0.0.1:50826_solr ] o.a.s.c.AddReplicaCmd Node Identified 127.0.0.1:50823_solr for creating new replica [junit4] 2> 2205642 INFO (OverseerStateUpdate-98295354502676492-127.0.0.1:50826_solr-n_0000000000) [n:127.0.0.1:50826_solr ] o.a.s.c.o.SliceMutator createReplica() { [junit4] 2> "operation":"addreplica", [junit4] 2> "collection":"testCreateShardRepFactor", [junit4] 2> "shard":"x", [junit4] 2> "core":"testCreateShardRepFactor_x_replica_n1", [junit4] 2> "state":"down", [junit4] 2> "base_url":"http://127.0.0.1:50823/solr";, [junit4] 2> "node_name":"127.0.0.1:50823_solr", [junit4] 2> "type":"NRT"} [junit4] 2> 2205751 INFO (zkCallback-2577-thread-2-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205751 INFO (zkCallback-2577-thread-1-processing-n:127.0.0.1:50824_solr) [n:127.0.0.1:50824_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205752 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205751 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205850 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&coreNodeName=core_node3&collection.configName=conf&name=testCreateShardRepFactor_x_replica_n1&action=CREATE&collection=testCreateShardRepFactor&shard=x&wt=javabin&version=2&replicaType=NRT [junit4] 2> 2205851 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores [junit4] 2> 2205866 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.1.0 [junit4] 2> 2205872 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.s.IndexSchema [testCreateShardRepFactor_x_replica_n1] Schema name=cloud-dynamic [junit4] 2> 2205891 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.s.IndexSchema Loaded schema cloud-dynamic/1.6 with uniqueid field id [junit4] 2> 2205892 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.c.CoreContainer Creating SolrCore 'testCreateShardRepFactor_x_replica_n1' using configuration from collection testCreateShardRepFactor, trusted=true [junit4] 2> 2205892 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr_50823.solr.core.testCreateShardRepFactor.x.replica_n1' (registry 'solr.core.testCreateShardRepFactor.x.replica_n1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@177dd481 [junit4] 2> 2205892 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 2205892 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.c.SolrCore [[testCreateShardRepFactor_x_replica_n1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node2/testCreateShardRepFactor_x_replica_n1], dataDir=[/Users/jenkins/workspace/Lucene-Solr-7.x-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CustomCollectionTest_DEDE741B70AABF46-001/tempDir-001/node2/./testCreateShardRepFactor_x_replica_n1/data/] [junit4] 2> 2205962 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog [junit4] 2> 2205962 INFO (qtp1655650061-18199) [n:127.0.0.1:50823_solr c:testCreateShardRepFactor s:x r:core_node3 x:testCreateShardRepFactor_x_replica_n1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 [junit4] 2> 2205962 INFO (zkCallback-2576-thread-2-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/testCreateShardRepFactor/state.json] for collection [testCreateShardRepFactor] has occurred - updating... (live nodes size: [4]) [junit4] 2> 2205962 INFO (zkCallback-2576-thread-1-processing-n:127.0.0.1:50822_solr) [n:127.0.0.1:50822_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEve [...truncated too long message...] t] [junit4] > at java.lang.Thread.sleep(Native Method) [junit4] > at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 5) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at java.lang.Thread.sleep(Native Method) [junit4] > at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) [junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) [junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) [junit4] > 6) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 7) Thread[id=19269, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-EventThread, state=WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) [junit4] > at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) [junit4] > at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) [junit4] > at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:501) [junit4] > 8) Thread[id=19263, name=Connection evictor, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at java.lang.Thread.sleep(Native Method) [junit4] > at org.apache.http.impl.client.IdleConnectionEvictor$1.run(IdleConnectionEvictor.java:66) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 9) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated: [junit4] > 1) Thread[id=19288, name=zkCallback-2726-thread-6, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 2) Thread[id=19285, name=zkCallback-2726-thread-3, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 3) Thread[id=19287, name=zkCallback-2726-thread-5, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 4) Thread[id=19268, name=TEST-MissingSegmentRecoveryTest.testLeaderRecovery-seed#[DEDE741B70AABF46]-SendThread(127.0.0.1:51458), state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at java.lang.Thread.sleep(Native Method) [junit4] > at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101) [junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:997) [junit4] > at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1060) [junit4] > 5) Thread[id=19286, name=zkCallback-2726-thread-4, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 6) Thread[id=19279, name=zkCallback-2726-thread-2, state=TIMED_WAITING, group=TGRP-MissingSegmentRecoveryTest] [junit4] > at sun.misc.Unsafe.park(Native Method) [junit4] > at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460) [junit4] > at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362) [junit4] > at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941) [junit4] > at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > at __randomizedtesting.SeedInfo.seed([DEDE741B70AABF46]:0) [junit4] Completed [521/728 (3!)] on J1 in 119.06s, 1 test, 1 failure, 2 errors <<< FAILURES! [...truncated 43984 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org
